run-test: don't report leaks that don't fail test

LeakSanitizer will report a leak when allocating a string in
SuperviseThread.  It's unclear why this is the case, but upon inspecting
the code, it seems like a false positive. The stack trace is as follows:

=================================================================
==93677==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 58 byte(s) in 1 object(s) allocated from:
    #0 0x5318c8 in operator new(unsigned long) /data/8/awong/kudu/thirdparty/src/llvm-6.0.0.src/projects/compiler-rt/lib/asan/asan_new_delete.cc:92
    #1 0x3ae3a9c3c8 in std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) (/usr/lib64/libstdc++.so.6+0x3ae3a9c3c8)
    #2 0x3ae3a9d19a in std::string::_Rep::_M_clone(std::allocator<char> const&, unsigned long) (/usr/lib64/libstdc++.so.6+0x3ae3a9d19a)
    #3 0x3ae3a9d5eb in std::string::reserve(unsigned long) (/usr/lib64/libstdc++.so.6+0x3ae3a9d5eb)
    #4 0x3ae3a9d770 in std::string::append(unsigned long, char) (/usr/lib64/libstdc++.so.6+0x3ae3a9d770)
    #5 0x7f518f799c12 in strings::SubstituteAndAppend(std::string*, StringPiece, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&) ../src/kudu/gutil/strings/substitute.cc:110:3
    #6 0x536e76 in strings::Substitute(StringPiece, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&, strings::internal::SubstituteArg const&) ../src/kudu/gutil/strings/substitute.h:188:3
    #7 0x7f5190590860 in kudu::Thread::SuperviseThread(void*) ../src/kudu/util/thread.cc:607:17
    #8 0x3ae0e079d0 in start_thread (/lib64/libpthread.so.0+0x3ae0e079d0)
    #9 0x3ae0ae88fc in clone (/lib64/libc.so.6+0x3ae0ae88fc)

This appears to be affecting a number tests, but generally only lines #0
and #1 are present in the logs, making them difficult to debug (a
developer would have to rerun the test with specific ASAN_OPTIONS to
unwind the stacktrace more). Namely, exactly_once_writes-itest
(KUDU-2517), kudu-admin-test (KUDU-2583), and rebalancer-tool-test
(untracked via Jira) all show the top of the above stack trace, and
based on the full stack trace, it seems these are all false positives.

The presence of issues like
google/sanitizers#757 confirms that
LeakSanitizer can report false positives in workloads with high
concurrency. Generally, the test binary will return an error in the face
of real leaks, but in tests like the ones mentioned, the test may log
messages reporting leaks, but not actually return an error because the
"leak" was transient (e.g. see GenericServiceImpl::CheckLeaks).

We currently inject errors into JUnit XML report if any leaks are
reported, even for false positives, since the leak messages still find
their way into the logs. This patch updates this to only inject these
errors if the test also returned an error.

For clarity, I also threw in a log statement to
GenericServiceImpl::CheckLeaks denoting false positives.

Change-Id: I1f199795c48bd9b6106110aae132ec165eb0f647
Reviewed-on: http://gerrit.cloudera.org:8080/11886
Tested-by: Kudu Jenkins
Reviewed-by: Andrew Wong <[email protected]>

build-support/run-test.sh

@@ -110,9 +110,11 @@ rm -f $LOGFILE $LOGFILE.gz
 
 if [ -n "$KUDU_COMPRESS_TEST_OUTPUT" ] && [ "$KUDU_COMPRESS_TEST_OUTPUT" -ne 0 ] ; then
   pipe_cmd=gzip
+  grep_cmd=$(which zgrep)
   LOGFILE=${LOGFILE}.gz
 else
   pipe_cmd=cat
+  grep_cmd=$(which grep)
 fi
 
 # Set a 15-minute timeout for tests run via 'make test'.
@@ -234,10 +236,10 @@ for ATTEMPT_NUMBER in $(seq 1 $TEST_EXECUTION_ATTEMPTS) ; do
   fi
 done
 
-# If we have a LeakSanitizer report, and XML reporting is configured, add a new test
-# case result to the XML file for the leak report. Otherwise Jenkins won't show
-# us which tests had LSAN errors.
-if zgrep --silent "ERROR: LeakSanitizer: detected memory leaks" $LOGFILE ; then
+# If the tests failed, we have a LeakSanitizer report, and XML reporting is
+# configured, add a new test case result to the XML file for the leak report.
+# Otherwise Jenkins won't show us that the tests had LSAN errors.
+if [[ "$STATUS" -ne "0" ]] && $grep_cmd --silent "ERROR: LeakSanitizer: detected memory leaks" $LOGFILE ; then
     echo Test had memory leaks. Editing XML
     perl -p -i -e '
     if (m#</testsuite>#) {

src/kudu/server/generic_service.cc

@@ -34,6 +34,7 @@
 #include "kudu/common/wire_protocol.h"
 #include "kudu/gutil/casts.h"
 #include "kudu/gutil/map-util.h"
+#include "kudu/gutil/strings/substitute.h" // IWYU pragma: keep
 #include "kudu/rpc/rpc_context.h"
 #include "kudu/server/server_base.h"
 #include "kudu/server/server_base.pb.h"
@@ -178,7 +179,14 @@ void GenericServiceImpl::CheckLeaks(const CheckLeaksRequestPB* /*req*/,
   bool has_leaks = true;
   for (int i = 0; i < 5; i++) {
     has_leaks = __lsan_do_recoverable_leak_check();
-    if (!has_leaks) break;
+    if (!has_leaks) {
+      if (i > 0) {
+        LOG(WARNING) << strings::Substitute("LeakSanitizer found a leak that went away after $0 "
+                                            "retries.\n", i)
+                     << "Treating it as a false positive and ignoring it.";
+      }
+      break;
+    }
     SleepFor(MonoDelta::FromMilliseconds(5));
   }