[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
```

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: 368373

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,48 @@
+// This test case checks for an old bug when using plug-ins that caused
+// the stack numbering to be incorrect.
+
+// 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())