From db9e2ff7afa96c0e533b55c5b2abbdcf755e8f46 Mon Sep 17 00:00:00 2001 From: Travis Downs Date: Mon, 16 Sep 2024 15:38:25 -0300 Subject: [PATCH] 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 | 46 ++++++++++++++++++++++++++++----------- scripts/seastar-addr2line | 9 +++++++- 2 files changed, 41 insertions(+), 14 deletions(-) diff --git a/scripts/addr2line.py b/scripts/addr2line.py index f2c4a49df4..31a7c97f17 100755 --- a/scripts/addr2line.py +++ b/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,13 +89,17 @@ 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): @@ -101,7 +107,9 @@ def __call__(self, address: str): 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[0-9a-f]+) (?P.+) (?P\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}") diff --git a/scripts/seastar-addr2line b/scripts/seastar-addr2line index dca3164219..88842a985b 100755 --- a/scripts/seastar-addr2line +++ b/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')