[compiler-rt] r251447 - [asan] On OS X, log reports to syslog and os_trace

Anna Zaks via llvm-commits llvm-commits at lists.llvm.org
Tue Oct 27 13:13:02 PDT 2015


Author: zaks
Date: Tue Oct 27 15:13:01 2015
New Revision: 251447

URL: http://llvm.org/viewvc/llvm-project?rev=251447&view=rev
Log:
[asan] On OS X, log reports to syslog and os_trace

When ASan currently detects a bug, by default it will only print out the text
of the report to stderr. This patch changes this behavior and writes the full
text of the report to syslog before we terminate the process. It also calls
os_trace (Activity Tracing available on OS X and iOS) with a message saying
that the report is available in syslog. This is useful, because this message
will be shown in the crash log.

For this to work, the patch makes sure we store the full report into
error_message_buffer unconditionally, and it also strips out ANSI escape
sequences from the report (they are used when producing colored reports).

I've initially tried to log to syslog during printing, which is done on Android
right now. The advantage is that if we crash during error reporting or the
produced error does not go through ScopedInErrorReport, we would still get a
(partial) message in the syslog. However, that solution is very problematic on
OS X. One issue is that the logging routine uses GCD, which may spawn a new
thread on its behalf. In many cases, the reporting logic locks threadRegistry,
which leads to deadlocks.

Reviewed at http://reviews.llvm.org/D13452

Modified:
    compiler-rt/trunk/lib/asan/asan_report.cc
    compiler-rt/trunk/lib/asan/tests/asan_test_main.cc
    compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.cc
    compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.h
    compiler-rt/trunk/lib/sanitizer_common/sanitizer_common_libcdep.cc
    compiler-rt/trunk/lib/sanitizer_common/sanitizer_flags.inc
    compiler-rt/trunk/lib/sanitizer_common/sanitizer_linux_libcdep.cc
    compiler-rt/trunk/lib/sanitizer_common/sanitizer_mac.cc
    compiler-rt/trunk/lib/sanitizer_common/sanitizer_printf.cc
    compiler-rt/trunk/lib/sanitizer_common/tests/sanitizer_common_test.cc
    compiler-rt/trunk/test/asan/lit.cfg
    compiler-rt/trunk/test/ubsan/lit.common.cfg

Modified: compiler-rt/trunk/lib/asan/asan_report.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/asan/asan_report.cc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/asan/asan_report.cc (original)
+++ compiler-rt/trunk/lib/asan/asan_report.cc Tue Oct 27 15:13:01 2015
@@ -31,6 +31,7 @@ static void (*error_report_callback)(con
 static char *error_message_buffer = nullptr;
 static uptr error_message_buffer_pos = 0;
 static uptr error_message_buffer_size = 0;
+static BlockingMutex error_message_buf_mutex(LINKER_INITIALIZED);
 
 struct ReportData {
   uptr pc;
@@ -46,16 +47,21 @@ static bool report_happened = false;
 static ReportData report_data = {};
 
 void AppendToErrorMessageBuffer(const char *buffer) {
-  if (error_message_buffer) {
-    uptr length = internal_strlen(buffer);
-    CHECK_GE(error_message_buffer_size, error_message_buffer_pos);
-    uptr remaining = error_message_buffer_size - error_message_buffer_pos;
-    internal_strncpy(error_message_buffer + error_message_buffer_pos,
-                     buffer, remaining);
-    error_message_buffer[error_message_buffer_size - 1] = '\0';
-    // FIXME: reallocate the buffer instead of truncating the message.
-    error_message_buffer_pos += Min(remaining, length);
+  BlockingMutexLock l(&error_message_buf_mutex);
+  if (!error_message_buffer) {
+    error_message_buffer_size = 1 << 16;
+    error_message_buffer =
+      (char*)MmapOrDie(error_message_buffer_size, __func__);
+    error_message_buffer_pos = 0;
   }
+  uptr length = internal_strlen(buffer);
+  CHECK_GE(error_message_buffer_size, error_message_buffer_pos);
+  uptr remaining = error_message_buffer_size - error_message_buffer_pos;
+  internal_strncpy(error_message_buffer + error_message_buffer_pos,
+                   buffer, remaining);
+  error_message_buffer[error_message_buffer_size - 1] = '\0';
+  // FIXME: reallocate the buffer instead of truncating the message.
+  error_message_buffer_pos += Min(remaining, length);
 }
 
 // ---------------------- Decorator ------------------------------ {{{1
@@ -664,8 +670,13 @@ class ScopedInErrorReport {
     // Print memory stats.
     if (flags()->print_stats)
       __asan_print_accumulated_stats();
-    if (error_report_callback) {
-      error_report_callback(error_message_buffer);
+    {
+      BlockingMutexLock l(&error_message_buf_mutex);
+      LogFullErrorReport(error_message_buffer);
+
+      if (error_report_callback) {
+        error_report_callback(error_message_buffer);
+      }
     }
     Report("ABORTING\n");
     Die();
@@ -1061,13 +1072,8 @@ void __asan_report_error(uptr pc, uptr b
 }
 
 void NOINLINE __asan_set_error_report_callback(void (*callback)(const char*)) {
+  BlockingMutexLock l(&error_message_buf_mutex);
   error_report_callback = callback;
-  if (callback) {
-    error_message_buffer_size = 1 << 16;
-    error_message_buffer =
-        (char*)MmapOrDie(error_message_buffer_size, __func__);
-    error_message_buffer_pos = 0;
-  }
 }
 
 void __asan_describe_address(uptr addr) {

Modified: compiler-rt/trunk/lib/asan/tests/asan_test_main.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/asan/tests/asan_test_main.cc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/asan/tests/asan_test_main.cc (original)
+++ compiler-rt/trunk/lib/asan/tests/asan_test_main.cc Tue Oct 27 15:13:01 2015
@@ -19,7 +19,8 @@ extern "C" const char* __asan_default_op
 #if SANITIZER_MAC
   // On Darwin, we default to `abort_on_error=1`, which would make tests run
   // much slower. Let's override this and run lit tests with 'abort_on_error=0'.
-  return "symbolize=false:abort_on_error=0";
+  // Also, make sure we do not overwhelm the syslog while testing.
+  return "symbolize=false:abort_on_error=0:log_to_syslog=0";
 #else
   return "symbolize=false";
 #endif

Modified: compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.cc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.cc (original)
+++ compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.cc Tue Oct 27 15:13:01 2015
@@ -295,6 +295,40 @@ void ReportErrorSummary(const char *erro
 }
 #endif
 
+// Removes the ANSI escape sequences from the input string (in-place).
+void RemoveANSIEscapeSequencesFromString(char *str) {
+  if (!str)
+    return;
+
+  // We are going to remove the escape sequences in place.
+  char *s = str;
+  char *z = str;
+  while (*s != '\0') {
+    CHECK_GE(s, z);
+    // Skip over ANSI escape sequences with pointer 's'.
+    if (*s == '\033' && *(s + 1) == '[') {
+      s = internal_strchrnul(s, 'm');
+      if (*s == '\0') {
+        break;
+      }
+      s++;
+      continue;
+    }
+    // 's' now points at a character we want to keep. Copy over the buffer
+    // content if the escape sequence has been perviously skipped andadvance
+    // both pointers.
+    if (s != z)
+      *z = *s;
+
+    // If we have not seen an escape sequence, just advance both pointers.
+    z++;
+    s++;
+  }
+
+  // Null terminate the string.
+  *z = '\0';
+}
+
 void LoadedModule::set(const char *module_name, uptr base_address) {
   clear();
   full_name_ = internal_strdup(module_name);

Modified: compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.h
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.h?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.h (original)
+++ compiler-rt/trunk/lib/sanitizer_common/sanitizer_common.h Tue Oct 27 15:13:01 2015
@@ -162,6 +162,7 @@ void SetLowLevelAllocateCallback(LowLeve
 // IO
 void RawWrite(const char *buffer);
 bool ColorizeReports();
+void RemoveANSIEscapeSequencesFromString(char *buffer);
 void Printf(const char *format, ...);
 void Report(const char *format, ...);
 void SetPrintfAndReportCallback(void (*callback)(const char *));
@@ -648,13 +649,27 @@ enum AndroidApiLevel {
   ANDROID_POST_LOLLIPOP = 23
 };
 
+void WriteToSyslog(const char *buffer);
+
+#if SANITIZER_MAC
+void LogFullErrorReport(const char *error_message_buffer);
+#else
+INLINE void LogFullErrorReport(const char *error_message_buffer) {}
+#endif
+
+#if SANITIZER_LINUX || SANITIZER_MAC
+void WriteOneLineToSyslog(const char *s);
+#else
+INLINE void WriteOneLineToSyslog(const char *s) {}
+#endif
+
 #if SANITIZER_LINUX
 // Initialize Android logging. Any writes before this are silently lost.
 void AndroidLogInit();
-void WriteToSyslog(const char *buffer);
+bool ShouldLogAfterPrintf();
 #else
 INLINE void AndroidLogInit() {}
-INLINE void WriteToSyslog(const char *buffer) {}
+INLINE bool ShouldLogAfterPrintf() { return false; }
 #endif
 
 #if SANITIZER_ANDROID

Modified: compiler-rt/trunk/lib/sanitizer_common/sanitizer_common_libcdep.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/sanitizer_common/sanitizer_common_libcdep.cc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/sanitizer_common/sanitizer_common_libcdep.cc (original)
+++ compiler-rt/trunk/lib/sanitizer_common/sanitizer_common_libcdep.cc Tue Oct 27 15:13:01 2015
@@ -12,6 +12,7 @@
 //===----------------------------------------------------------------------===//
 
 #include "sanitizer_common.h"
+#include "sanitizer_allocator_internal.h"
 #include "sanitizer_flags.h"
 #include "sanitizer_stackdepot.h"
 #include "sanitizer_stacktrace.h"
@@ -116,6 +117,27 @@ void BackgroundThread(void *arg) {
   }
 }
 
+void WriteToSyslog(const char *buffer) {
+  char *copy = internal_strdup(buffer);
+  char *p = copy;
+  char *q;
+
+  // Remove color sequences since syslogs cannot print them.
+  RemoveANSIEscapeSequencesFromString(copy);
+
+  // Print one line at a time.
+  // syslog, at least on Android, has an implicit message length limit.
+  do {
+    q = internal_strchr(p, '\n');
+    if (q)
+      *q = '\0';
+    WriteOneLineToSyslog(p);
+    if (q)
+      p = q + 1;
+  } while (q);
+  InternalFree(copy);
+}
+
 void MaybeStartBackgroudThread() {
 #if SANITIZER_LINUX  // Need to implement/test on other platforms.
   // Start the background thread if one of the rss limits is given.

Modified: compiler-rt/trunk/lib/sanitizer_common/sanitizer_flags.inc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/sanitizer_common/sanitizer_flags.inc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/sanitizer_common/sanitizer_flags.inc (original)
+++ compiler-rt/trunk/lib/sanitizer_common/sanitizer_flags.inc Tue Oct 27 15:13:01 2015
@@ -56,7 +56,7 @@ COMMON_FLAG(
     "Mention name of executable when reporting error and "
     "append executable name to logs (as in \"log_path.exe_name.pid\").")
 COMMON_FLAG(
-    bool, log_to_syslog, SANITIZER_ANDROID,
+    bool, log_to_syslog, SANITIZER_ANDROID || SANITIZER_MAC,
     "Write all sanitizer output to syslog in addition to other means of "
     "logging.")
 COMMON_FLAG(

Modified: compiler-rt/trunk/lib/sanitizer_common/sanitizer_linux_libcdep.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/sanitizer_common/sanitizer_linux_libcdep.cc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/sanitizer_common/sanitizer_linux_libcdep.cc (original)
+++ compiler-rt/trunk/lib/sanitizer_common/sanitizer_linux_libcdep.cc Tue Oct 27 15:13:01 2015
@@ -548,16 +548,16 @@ void AndroidLogInit() {
   atomic_store(&android_log_initialized, 1, memory_order_release);
 }
 
-static bool IsSyslogAvailable() {
+bool ShouldLogAfterPrintf() {
   return atomic_load(&android_log_initialized, memory_order_acquire);
 }
 #else
 void AndroidLogInit() {}
 
-static bool IsSyslogAvailable() { return true; }
+bool ShouldLogAfterPrintf() { return true; }
 #endif  // SANITIZER_ANDROID
 
-static void WriteOneLineToSyslog(const char *s) {
+void WriteOneLineToSyslog(const char *s) {
 #if SANITIZER_ANDROID &&__ANDROID_API__ < 21
   __android_log_write(ANDROID_LOG_INFO, NULL, s);
 #else
@@ -565,24 +565,6 @@ static void WriteOneLineToSyslog(const c
 #endif
 }
 
-void WriteToSyslog(const char *buffer) {
-  if (!IsSyslogAvailable())
-    return;
-  char *copy = internal_strdup(buffer);
-  char *p = copy;
-  char *q;
-  // syslog, at least on Android, has an implicit message length limit.
-  // Print one line at a time.
-  do {
-    q = internal_strchr(p, '\n');
-    if (q)
-      *q = '\0';
-    WriteOneLineToSyslog(p);
-    if (q)
-      p = q + 1;
-  } while (q);
-  InternalFree(copy);
-}
 #endif // SANITIZER_LINUX
 
 } // namespace __sanitizer

Modified: compiler-rt/trunk/lib/sanitizer_common/sanitizer_mac.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/sanitizer_common/sanitizer_mac.cc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/sanitizer_common/sanitizer_mac.cc (original)
+++ compiler-rt/trunk/lib/sanitizer_common/sanitizer_mac.cc Tue Oct 27 15:13:01 2015
@@ -36,12 +36,14 @@
 extern char **environ;
 #endif
 
+#include <asl.h>
 #include <errno.h>
 #include <fcntl.h>
 #include <libkern/OSAtomic.h>
 #include <mach-o/dyld.h>
 #include <mach/mach.h>
 #include <mach/vm_statistics.h>
+#include <os/trace.h>
 #include <pthread.h>
 #include <sched.h>
 #include <signal.h>
@@ -371,6 +373,45 @@ uptr GetRSS() {
   return info.resident_size;
 }
 
+static BlockingMutex syslog_lock(LINKER_INITIALIZED);
+
+void WriteOneLineToSyslog(const char *s) {
+  syslog_lock.CheckLocked();
+  asl_log(nullptr, nullptr, ASL_LEVEL_ERR, "%s", s);
+}
+
+void LogFullErrorReport(const char *buffer) {
+  // Log with os_trace. This will make it into the crash log.
+  if (GetMacosVersion() >= MACOS_VERSION_MAVERICKS) {
+    // os_trace requires the message (format parameter) to be a string literal.
+    if (internal_strncmp(SanitizerToolName, "AddressSanitizer",
+                         sizeof("AddressSanitizer") - 1) == 0)
+      os_trace("Address Sanitizer reported a failure.");
+    else if (internal_strncmp(SanitizerToolName, "UndefinedBehaviorSanitizer",
+                              sizeof("UndefinedBehaviorSanitizer") - 1) == 0)
+      os_trace("Undefined Behavior Sanitizer reported a failure.");
+    else if (internal_strncmp(SanitizerToolName, "ThreadSanitizer",
+                              sizeof("ThreadSanitizer") - 1) == 0)
+      os_trace("Thread Sanitizer reported a failure.");
+    else
+      os_trace("Sanitizer tool reported a failure.");
+
+    if (common_flags()->log_to_syslog)
+      os_trace("Consult syslog for more information.");
+  }
+
+  // Log to syslog.
+  // The logging on OS X may call pthread_create so we need the threading
+  // environment to be fully initialized. Also, this should never be called when
+  // holding the thread registry lock since that may result in a deadlock. If
+  // the reporting thread holds the thread registry mutex, and asl_log waits
+  // for GCD to dispatch a new thread, the process will deadlock, because the
+  // pthread_create wrapper needs to acquire the lock as well.
+  BlockingMutexLock l(&syslog_lock);
+  if (common_flags()->log_to_syslog)
+    WriteToSyslog(buffer);
+}
+
 void *internal_start_thread(void (*func)(void *arg), void *arg) { return 0; }
 void internal_join_thread(void *th) { }
 

Modified: compiler-rt/trunk/lib/sanitizer_common/sanitizer_printf.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/sanitizer_common/sanitizer_printf.cc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/sanitizer_common/sanitizer_printf.cc (original)
+++ compiler-rt/trunk/lib/sanitizer_common/sanitizer_printf.cc Tue Oct 27 15:13:01 2015
@@ -278,7 +278,7 @@ static void SharedPrintfCode(bool append
 #   undef CHECK_NEEDED_LENGTH
   }
   RawWrite(buffer);
-  if (common_flags()->log_to_syslog)
+  if (common_flags()->log_to_syslog && ShouldLogAfterPrintf())
     WriteToSyslog(buffer);
   CallPrintfAndReportCallback(buffer);
   // If we had mapped any memory, clean up.

Modified: compiler-rt/trunk/lib/sanitizer_common/tests/sanitizer_common_test.cc
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/sanitizer_common/tests/sanitizer_common_test.cc?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/lib/sanitizer_common/tests/sanitizer_common_test.cc (original)
+++ compiler-rt/trunk/lib/sanitizer_common/tests/sanitizer_common_test.cc Tue Oct 27 15:13:01 2015
@@ -208,6 +208,30 @@ TEST(SanitizerCommon, StripPathPrefix) {
   EXPECT_STREQ("file.h", StripPathPrefix("/usr/lib/./file.h", "/usr/lib/"));
 }
 
+TEST(SanitizerCommon, RemoveANSIEscapeSequencesFromString) {
+  RemoveANSIEscapeSequencesFromString(nullptr);
+  const char *buffs[22] = {
+    "Default",                                "Default",
+    "\033[95mLight magenta",                  "Light magenta",
+    "\033[30mBlack\033[32mGreen\033[90mGray", "BlackGreenGray",
+    "\033[106mLight cyan \033[107mWhite ",    "Light cyan White ",
+    "\033[31mHello\033[0m World",             "Hello World",
+    "\033[38;5;82mHello \033[38;5;198mWorld", "Hello World",
+    "123[653456789012",                       "123[653456789012",
+    "Normal \033[5mBlink \033[25mNormal",     "Normal Blink Normal",
+    "\033[106m\033[107m",                     "",
+    "",                                       "",
+    " ",                                      " ",
+  };
+
+  for (size_t i = 0; i < ARRAY_SIZE(buffs); i+=2) {
+    char *buffer_copy = internal_strdup(buffs[i]);
+    RemoveANSIEscapeSequencesFromString(buffer_copy);
+    EXPECT_STREQ(buffer_copy, buffs[i+1]);
+    InternalFree(buffer_copy);
+  }
+}
+
 TEST(SanitizerCommon, InternalScopedString) {
   InternalScopedString str(10);
   EXPECT_EQ(0U, str.length());

Modified: compiler-rt/trunk/test/asan/lit.cfg
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/test/asan/lit.cfg?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/test/asan/lit.cfg (original)
+++ compiler-rt/trunk/test/asan/lit.cfg Tue Oct 27 15:13:01 2015
@@ -34,7 +34,9 @@ default_asan_opts = ''
 if config.host_os == 'Darwin':
   # On Darwin, we default to `abort_on_error=1`, which would make tests run
   # much slower. Let's override this and run lit tests with 'abort_on_error=0'.
+  # Also, make sure we do not overwhelm the syslog while testing.
   default_asan_opts = 'abort_on_error=0'
+  default_asan_opts += ':log_to_syslog=0'
 if default_asan_opts:
   config.environment['ASAN_OPTIONS'] = default_asan_opts
   default_asan_opts += ':'

Modified: compiler-rt/trunk/test/ubsan/lit.common.cfg
URL: http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/test/ubsan/lit.common.cfg?rev=251447&r1=251446&r2=251447&view=diff
==============================================================================
--- compiler-rt/trunk/test/ubsan/lit.common.cfg (original)
+++ compiler-rt/trunk/test/ubsan/lit.common.cfg Tue Oct 27 15:13:01 2015
@@ -42,6 +42,7 @@ if config.host_os == 'Darwin':
   # On Darwin, we default to `abort_on_error=1`, which would make tests run
   # much slower. Let's override this and run lit tests with 'abort_on_error=0'.
   default_ubsan_opts += ['abort_on_error=0']
+  default_ubsan_opts += ['log_to_syslog=0']
 default_ubsan_opts_str = ':'.join(default_ubsan_opts)
 if default_ubsan_opts_str:
   config.environment['UBSAN_OPTIONS'] = default_ubsan_opts_str




More information about the llvm-commits mailing list