seastar-addr2line: add --debug arg

This adds the --debug argument to the seastar-addr2line script.

--debug will output additional logging/diagnostics to stderr (the
primary output goes to stdout), which can be helpful to diagnose what
is going on when addr2line does not decode things as expected.

Right now the debugging is targeted mostly at the specific flow of
decoding the addresses in the child process, but .debug(...) calls
can be added anywhere else if it is convenient.

scripts/addr2line.py

@@ -50,7 +50,8 @@ class Addr2Line:
         r"(.*0x0: \?\? at \?\?:0\n)"  # llvm-addr2line pattern
         )
 
-    def __init__(self, binary: str, concise: bool = False, cmd_path: str = "addr2line"):
+    def __init__(self, parent: 'BacktraceResolver', binary: str, concise: bool = False, cmd_path: str = "addr2line"):
+        self._parent = parent
         self._binary = binary
 
         # Print warning if binary has no debug info according to `file`.
@@ -61,8 +62,9 @@ def __init__(self, binary: str, concise: bool = False, cmd_path: str = "addr2lin
         if s.find('ELF') >= 0 and s.find('debug_info', len(self._binary)) < 0:
             print('{}'.format(s))
 
-        options = f"-{'C' if not concise else ''}fpia"
-        self._input_proc = subprocess.Popen([cmd_path, options, "-e", self._binary], stdin=subprocess.PIPE, stdout=subprocess.PIPE, universal_newlines=True)
+        args = [cmd_path, f"-{'C' if not concise else ''}fpia", "-e", self._binary]
+        self._parent.debug(f"Addr2line invoking: {' '.join(args)}")
+        self._input_proc = subprocess.Popen(args, stdin=subprocess.PIPE, stdout=subprocess.PIPE, universal_newlines=True)
         if concise:
             self._output_proc = subprocess.Popen(["c++filt", "-p"], stdin=self._input_proc.stdout, stdout=subprocess.PIPE, universal_newlines=True)
         else:
@@ -87,21 +89,27 @@ def _output(self):
         return notNone(self._output_proc.stdout)
 
     def _read_resolved_address(self):
-        res = self._output().readline()
+        first = self._output().readline()
+        self._parent.debug('Addr2Line read output (first): ', first)
         # remove the address
-        res = res.split(': ', 1)[1]
-        line = ''
-        while Addr2Line.dummy_pattern.fullmatch(line) is None:
-            res += line
+        res = first.split(': ', 1)[1]
+        while True:
             line = self._output().readline()
+            if Addr2Line.dummy_pattern.fullmatch(line):
+                self._parent.debug('Addr2Line read output (    dummy): ', line)
+                break
+            self._parent.debug('Addr2Line read output (non-dummy): ', line)
+            res += line
         return res
 
     def __call__(self, address: str):
         if self._missing:
             return " ".join([self._binary, address, '\n'])
         # We print a dummy 0x0 address after the address we are interested in
         # which we can look for in _read_address
-        self._input.write(address + '\n0x0\n')
+        inputline = address + '\n0x0\n'
+        self._parent.debug('Add2Line sending input to stdin:', inputline)
+        self._input.write(inputline)
         self._input.flush()
         return self._read_resolved_address()
 
@@ -110,7 +118,7 @@ class KernelResolver:
 
     LAST_SYMBOL_MAX_SIZE = 1024
 
-    def __init__(self, kallsyms : str = '/proc/kallsyms'):
+    def __init__(self, parent: 'BacktraceResolver', kallsyms : str = '/proc/kallsyms'):
         syms : list[tuple[int, str]] = []
         ksym_re = re.compile(r'(?P<addr>[0-9a-f]+) (?P<type>.+) (?P<name>\S+)')
         warnings_left = 10
@@ -285,7 +293,8 @@ def get_prefix(s: Optional[str]):
             #print(f">>> '{line}': None")
             return None
 
-    def __init__(self, executable: str, kallsyms: str = '/proc/kallsyms', before_lines: int = 1, context_re: Optional[str] = '', verbose: bool = False, concise: bool = False, cmd_path: str = 'addr2line'):
+    def __init__(self, executable: str, kallsyms: str = '/proc/kallsyms', before_lines: int = 1, context_re: Optional[str] = '', verbose: bool = False, concise: bool = False, cmd_path: str = 'addr2line', debug: bool = False):
+        self._debug = debug
         self._executable = executable
         self._kallsyms = kallsyms
         self._current_backtrace: list[tuple[str, str]] = []
@@ -305,12 +314,17 @@ def __init__(self, executable: str, kallsyms: str = '/proc/kallsyms', before_lin
         self._get_resolver_for_module(self._executable) # fail fast if there is something wrong with the exe resolver
         self.parser = self.BacktraceParser()
 
+    def debug(self, *args: Any):
+        if self._debug:
+            print('DEBUG >>', *args, file=sys.stderr)
+
     def _get_resolver_for_module(self, module: str):
         if not module in self._known_modules:
             if module == KERNEL_MODULE:
-                resolver = KernelResolver(kallsyms=self._kallsyms)
+                resolver = KernelResolver(self, kallsyms=self._kallsyms)
             else:
-                resolver = Addr2Line(module, self._concise, self._cmd_path)
+                resolver = Addr2Line(self, module, self._concise, self._cmd_path)
+            self.debug(f'Adding resolver {resolver} for module: {module}')
             self._known_modules[module] = resolver
         return self._known_modules[module]
 
@@ -370,6 +384,8 @@ def _print_current_backtrace(self):
 
         self._known_backtraces[backtrace] = self._i
 
+        self.debug(f'Resolving and printing parsed backtrace with {len(self._current_backtrace)} frames')
+
         print("[Backtrace #{}]".format(self._i))
 
         for module, addr in self._current_backtrace:
@@ -384,6 +400,7 @@ def __call__(self, line: str):
         res = self.parser(line)
 
         if not res:
+            self.debug('INPUT LINE [NO MATCH]:', line)
             self._print_current_backtrace()
             if self._before_lines > 0:
                 self._before_lines_queue.append(line)
@@ -392,8 +409,10 @@ def __call__(self, line: str):
             else:
                 pass # when == 0 no non-backtrace lines are printed
         elif res['type'] == self.BacktraceParser.Type.SEPARATOR:
+            self.debug('INPUT LINE [SEPARATOR]:', line)
             pass
         elif res['type'] == self.BacktraceParser.Type.ADDRESS:
+            self.debug('INPUT LINE [ADDRESS]:', line)
             addresses = cast(list[dict[str, Any]], res['addresses'])
             if len(addresses) > 1:
                 self._print_current_backtrace()
@@ -407,6 +426,7 @@ def __call__(self, line: str):
             if len(addresses) > 1:
                 self._print_current_backtrace()
         else:
+            self.debug('INPUT LINE [UNKNOWN]:', line)
             print(f"Unknown '{line}': {res}")
             raise RuntimeError("Unknown result type {res}")
 

scripts/seastar-addr2line

@@ -302,6 +302,12 @@ There are three operational modes:
         help='Make resolved backtraces verbose, prepend to each line the module'
         ' it originates from, as well as the address being resolved')
 
+    cmdline_parser.add_argument(
+        '-d',
+        '--debug',
+        action='store_true',
+        help='Emit debug logging to stderr.')
+
     cmdline_parser.add_argument(
         '-t',
         '--test',
@@ -344,7 +350,8 @@ There are three operational modes:
                            before_lines=args.before,
                            context_re=args.match,
                            verbose=args.verbose,
-                           cmd_path=args.addr2line) as resolve:
+                           cmd_path=args.addr2line,
+                           debug=args.debug) as resolve:
         for line in list(lines):
             resolve(line.strip() + '\n')