[asan_symbolize] Fix bug where the frame counter was not incremented.

Summary:
This bug occurred when a plug-in requested that a binary not be
symbolized while the script is trying to symbolize a stack frame. In
this case `self.frame_no` would not be incremented. This would cause
subsequent stack frames that are symbolized to be incorrectly numbered.

To fix this `get_symbolized_lines()` has been modified to take an
argument that indicates whether the stack frame counter should
incremented. In `process_line_posix()` `get_symbolized_lines(None, ...)`
is now used in in the case where we don't want to symbolize a line so
that we can keep the frame counter increment in a single function.

A test case is included. The test uses a dummy plugin that always asks
`asan_symbolize.py` script to not symbolize the first binary that the
script asks about. Prior to the patch this would cause the output to
script to look something like

```
  #0 0x0
  #0 0x0 in do_access
  #1 0x0 in main
```

This is the second attempt at landing this patch. The first (r368373)
failed due to failing some android bots and so was reverted in r368472.
The new test is now disabled for Android. It turns out that the patch
also fails for iOS too so it is also disabled for that family of
platforms too.

rdar://problem/49476995

Reviewers: kubamracek, yln, samsonov, dvyukov, vitalybuka

Subscribers: #sanitizers, llvm-commits

Tags: #llvm, #sanitizers

Differential Revision: https://reviews.llvm.org/D65495

llvm-svn: 368603

compiler-rt/lib/asan/scripts/asan_symbolize.py

@@ -431,10 +431,13 @@ class SymbolizationLoop(object):
     assert result
     return result
 
-  def get_symbolized_lines(self, symbolized_lines):
+  def get_symbolized_lines(self, symbolized_lines, inc_frame_counter=True):
     if not symbolized_lines:
+      if inc_frame_counter:
+        self.frame_no += 1
       return [self.current_line]
     else:
+      assert inc_frame_counter
       result = []
       for symbolized_frame in symbolized_lines:
         result.append('    #%s %s' % (str(self.frame_no), symbolized_frame.rstrip()))
@@ -464,15 +467,17 @@ class SymbolizationLoop(object):
     match = re.match(stack_trace_line_format, line)
     if not match:
       logging.debug('Line "{}" does not match regex'.format(line))
-      return [self.current_line]
+      # Not a frame line so don't increment the frame counter.
+      return self.get_symbolized_lines(None, inc_frame_counter=False)
     logging.debug(line)
     _, frameno_str, addr, binary, offset = match.groups()
+
     if not self.using_module_map and not os.path.isabs(binary):
       # Do not try to symbolicate if the binary is just the module file name
       # and a module map is unavailable.
       # FIXME(dliew): This is currently necessary for reports on Darwin that are
       # partially symbolicated by `atos`.
-      return [self.current_line]
+      return self.get_symbolized_lines(None)
     arch = ""
     # Arch can be embedded in the filename, e.g.: "libabc.dylib:x86_64h"
     colon_pos = binary.rfind(":")
@@ -491,7 +496,7 @@ class SymbolizationLoop(object):
     if binary is None:
       # The binary filter has told us this binary can't be symbolized.
       logging.debug('Skipping symbolication of binary "%s"', original_binary)
-      return [self.current_line]
+      return self.get_symbolized_lines(None)
     symbolized_line = self.symbolize_address(addr, binary, offset, arch)
     if not symbolized_line:
       if original_binary != binary:

compiler-rt/test/asan/TestCases/Posix/asan_symbolize_script/plugin_wrong_frame_number_bug.cpp

@@ -0,0 +1,50 @@
+// This test case checks for an old bug when using plug-ins that caused
+// the stack numbering to be incorrect.
+// UNSUPPORTED: android
+// UNSUPPORTED: ios
+
+// RUN: %clangxx_asan -O0 -g %s -o %t
+// RUN: %env_asan_opts=symbolize=0 not %run %t DUMMY_ARG > %t.asan_report 2>&1
+// RUN: %asan_symbolize --log-level debug --log-dest %t_debug_log_output.txt -l %t.asan_report --plugins %S/plugin_wrong_frame_number_bug.py > %t.asan_report_sym
+// RUN: FileCheck --input-file=%t.asan_report_sym %s
+
+#include <stdlib.h>
+
+int* p;
+extern "C" {
+
+void bug() {
+  free(p);
+}
+
+void foo(bool call_bug) {
+  if (call_bug)
+    bug();
+}
+
+// This indirection exists so that the call stack
+// is reliably large enough.
+void do_access_impl() {
+  *p = 42;
+}
+
+void do_access() {
+  do_access_impl();
+}
+
+int main(int argc, char** argv) {
+  p = (int*) malloc(sizeof(p));
+  foo(argc > 1);
+  do_access();
+  free(p);
+  return 0;
+}
+}
+
+// Check that the numbering of the stackframes is correct.
+
+// CHECK: AddressSanitizer: heap-use-after-free
+// CHECK-NEXT: WRITE of size
+// CHECK-NEXT: #0 0x{{[0-9a-fA-F]+}}
+// CHECK-NEXT: #1 0x{{[0-9a-fA-F]+}} in do_access
+// CHECK-NEXT: #2 0x{{[0-9a-fA-F]+}} in main

compiler-rt/test/asan/TestCases/Posix/asan_symbolize_script/plugin_wrong_frame_number_bug.py

@@ -0,0 +1,31 @@
+import logging
+
+class FailOncePlugin(AsanSymbolizerPlugIn):
+  """
+    This is a simple plug-in that always claims
+    that a binary can't be symbolized on the first
+    call but succeeds for all subsequent calls.
+
+    This plug-in exists to reproduce an old bug
+    in the `asan_symbolize.py` script.
+
+    By failing the first symbolization request
+    we used to cause an early exit in `asan_symbolize.py`
+    that didn't increment the frame counter which
+    caused subsequent symbolization attempts to
+    print the wrong frame number.
+  """
+  def __init__(self):
+    self.should_fail = True
+    pass
+
+  def filter_binary_path(self, path):
+    logging.info('filter_binary_path called in NoOpPlugin')
+    if self.should_fail:
+      logging.info('Doing first fail')
+      self.should_fail = False
+      return None
+    logging.info('Doing succeed')
+    return path
+
+register_plugin(FailOncePlugin())