From b152c1020c6bec23b522a3a203c176e21e6b6ed3 Mon Sep 17 00:00:00 2001 From: Alexey Gerenkov Date: Tue, 13 Nov 2018 00:18:17 +0300 Subject: [PATCH] esp32: Adds logging level to core dump script --- components/espcoredump/espcoredump.py | 83 +++++++++++++++++++-------- docs/en/api-guides/core_dump.rst | 1 + 2 files changed, 59 insertions(+), 25 deletions(-) diff --git a/components/espcoredump/espcoredump.py b/components/espcoredump/espcoredump.py index 9e35465545..8a6c4e754f 100755 --- a/components/espcoredump/espcoredump.py +++ b/components/espcoredump/espcoredump.py @@ -25,6 +25,7 @@ import array import errno import base64 import binascii +import logging idf_path = os.getenv('IDF_PATH') if idf_path: @@ -328,7 +329,7 @@ class ESPCoreDumpElfFile(esptool.ELFFile): if len(section_header) == 0: raise ESPCoreDumpError("No section header found at offset %04x in ELF file." % section_header_offs) if len(section_header) % LEN_SEC_HEADER != 0: - print('WARNING: Unexpected ELF section header length %04x is not mod-%02x' % (len(section_header),LEN_SEC_HEADER)) + logging.warning('Unexpected ELF section header length %04x is not mod-%02x' % (len(section_header),LEN_SEC_HEADER)) # walk through the section header and extract all sections section_header_offsets = range(0, len(section_header), LEN_SEC_HEADER) @@ -344,7 +345,7 @@ class ESPCoreDumpElfFile(esptool.ELFFile): raise ESPCoreDumpError("ELF file has no STRTAB section at shstrndx %d" % shstrndx) _,sec_type,_,_,sec_size,sec_offs = read_section_header(shstrndx * LEN_SEC_HEADER) if sec_type != esptool.ELFFile.SEC_TYPE_STRTAB: - print('WARNING: ELF file has incorrect STRTAB section type 0x%02x' % sec_type) + logging.warning('ELF file has incorrect STRTAB section type 0x%02x' % sec_type) f.seek(sec_offs) string_table = f.read(sec_size) @@ -371,7 +372,7 @@ class ESPCoreDumpElfFile(esptool.ELFFile): if len(seg_table) == 0: raise ESPCoreDumpError("No program header table found at offset %04x in ELF file." % seg_table_offs) if len(seg_table) % LEN_SEG_HEADER != 0: - print('WARNING: Unexpected ELF program header table length %04x is not mod-%02x' % (len(seg_table),LEN_SEG_HEADER)) + logging.warning('Unexpected ELF program header table length %04x is not mod-%02x' % (len(seg_table),LEN_SEG_HEADER)) # walk through the program segment table and extract all segments seg_table_offs = range(0, len(seg_table), LEN_SEG_HEADER) @@ -566,7 +567,7 @@ class ESPCoreDumpLoader(object): os.remove(fname) except OSError as e: if e.errno != errno.ENOENT: - print("Warning failed to remove temp file '%s' (%d)!" % (fname, e.errno)) + logging.warning("Failed to remove temp file '%s' (%d)!" % (fname, e.errno)) def cleanup(self): """Cleans up loader resources @@ -605,16 +606,25 @@ class ESPCoreDumpLoader(object): stack_len_aligned = 4*(old_div(stack_len_aligned,4) + 1) core_off += self.ESP32_COREDUMP_TSK_HDR_SZ + logging.info("Read TCB %d bytes @ 0x%x" % (tcbsz_aligned, tcb_addr)) data = self.read_data(core_off, tcbsz_aligned) - if tcbsz != tcbsz_aligned: - core_elf.add_program_segment(tcb_addr, data[:tcbsz - tcbsz_aligned], ESPCoreDumpElfFile.PT_LOAD, ESPCoreDumpSegment.PF_R | ESPCoreDumpSegment.PF_W) - else: - core_elf.add_program_segment(tcb_addr, data, ESPCoreDumpElfFile.PT_LOAD, ESPCoreDumpSegment.PF_R | ESPCoreDumpSegment.PF_W) + try: + if tcbsz != tcbsz_aligned: + core_elf.add_program_segment(tcb_addr, data[:tcbsz - tcbsz_aligned], ESPCoreDumpElfFile.PT_LOAD, ESPCoreDumpSegment.PF_R | ESPCoreDumpSegment.PF_W) + else: + core_elf.add_program_segment(tcb_addr, data, ESPCoreDumpElfFile.PT_LOAD, ESPCoreDumpSegment.PF_R | ESPCoreDumpSegment.PF_W) + except ESPCoreDumpError as e: + logging.warning("Skip TCB %d bytes @ 0x%x. (Reason: %s)" % (tcbsz_aligned, tcb_addr, e)) + core_off += tcbsz_aligned + logging.info("Read stack %d bytes @ 0x%x" % (stack_len_aligned, stack_base)) data = self.read_data(core_off, stack_len_aligned) if stack_len != stack_len_aligned: data = data[:stack_len - stack_len_aligned] - core_elf.add_program_segment(stack_base, data, ESPCoreDumpElfFile.PT_LOAD, ESPCoreDumpSegment.PF_R | ESPCoreDumpSegment.PF_W) + try: + core_elf.add_program_segment(stack_base, data, ESPCoreDumpElfFile.PT_LOAD, ESPCoreDumpSegment.PF_R | ESPCoreDumpSegment.PF_W) + except ESPCoreDumpError as e: + logging.warning("Skip task's (%x) stack %d bytes @ 0x%x. (Reason: %s)" % (tcb_addr, stack_len_aligned, stack_base, e)) core_off += stack_len_aligned try: task_regs = self._get_registers_from_stack(data, stack_end > stack_top) @@ -628,12 +638,18 @@ class ESPCoreDumpLoader(object): notes += note # add notes - core_elf.add_program_segment(0, notes, ESPCoreDumpElfFile.PT_NOTE, 0) + try: + core_elf.add_program_segment(0, notes, ESPCoreDumpElfFile.PT_NOTE, 0) + except ESPCoreDumpError as e: + logging.warning("Skip NOTES segment %d bytes @ 0x%x. (Reason: %s)" % (len(notes), 0, e)) # add ROM text sections if rom_elf: for ps in rom_elf.program_segments: if ps.flags & ESPCoreDumpSegment.PF_X: - core_elf.add_program_segment(ps.addr, ps.data, ESPCoreDumpElfFile.PT_LOAD, ps.flags) + try: + core_elf.add_program_segment(ps.addr, ps.data, ESPCoreDumpElfFile.PT_LOAD, ps.flags) + except ESPCoreDumpError as e: + logging.warning("Skip ROM segment %d bytes @ 0x%x. (Reason: %s)" % (len(ps.data), ps.addr, e)) core_elf.e_type = ESPCoreDumpElfFile.ET_CORE core_elf.e_machine = ESPCoreDumpElfFile.EM_XTENSA @@ -739,11 +755,11 @@ class ESPCoreDumpFlashLoader(ESPCoreDumpLoader): tool_args[-2] = str(self. dump_sz) et_out = subprocess.check_output(tool_args) print(et_out.decode('utf-8')) - except subprocess.CalledProcessError as e: - print("esptool script execution failed with err %d" % e.returncode) - print("Command ran: '%s'" % e.cmd) - print("Command out:") - print(e.output) + except subprocess.CalledProcessError as e: + logging.error("esptool script execution failed with err %d" % e.returncode) + logging.info("Command ran: '%s'" % e.cmd) + logging.info("Command out:") + logging.info(e.output) if self.fcore_name: self.remove_tmp_file(self.fcore_name) raise e @@ -832,7 +848,7 @@ class GDBMIResultHandler(GDBMIOutRecordHandler): if self.result_str.startswith(','): self.result_str = self.result_str[1:] else: - print("Invalid result format: '%s'" % ln) + logging.error("Invalid result format: '%s'" % ln) else: self.result_str = '' return True @@ -852,7 +868,7 @@ class GDBMIResultHandler(GDBMIOutRecordHandler): return if self._parse_rc(ln, self.RC_EXIT): return - print("Unknown GDB/MI result: '%s'" % ln) + logging.error("Unknown GDB/MI result: '%s'" % ln) class GDBMIStreamConsoleHandler(GDBMIOutStreamHandler): @@ -882,7 +898,7 @@ def dbg_corefile(args): loader = ESPCoreDumpFlashLoader(args.off, port=args.port) core_fname = loader.create_corefile(args.save_core, rom_elf=rom_elf) if not core_fname: - print("Failed to create corefile!") + logging.error("Failed to create corefile!") loader.cleanup() return else: @@ -891,7 +907,7 @@ def dbg_corefile(args): loader = ESPCoreDumpFileLoader(core_fname, args.core_format == 'b64') core_fname = loader.create_corefile(args.save_core, rom_elf=rom_elf) if not core_fname: - print("Failed to create corefile!") + logging.error("Failed to create corefile!") loader.cleanup() return @@ -960,12 +976,12 @@ def info_corefile(args): p.stdin.write(bytearray("-interpreter-exec console \"%s\"\n" % gdb_cmd, encoding='utf-8')) gdbmi_read2prompt(p.stdout, handlers) if not handlers[GDBMIResultHandler.TAG].result_class or handlers[GDBMIResultHandler.TAG].result_class == GDBMIResultHandler.RC_EXIT: - print("GDB exited (%s / %s)!" % (handlers[GDBMIResultHandler.TAG].result_class, handlers[GDBMIResultHandler.TAG].result_str)) + logging.error("GDB exited (%s / %s)!" % (handlers[GDBMIResultHandler.TAG].result_class, handlers[GDBMIResultHandler.TAG].result_str)) p.wait() - print("Problem occured! GDB exited, restart it.") + logging.error("Problem occured! GDB exited, restart it.") p = gdbmi_start(handlers, []) elif handlers[GDBMIResultHandler.TAG].result_class != GDBMIResultHandler.RC_DONE: - print("GDB/MI command failed (%s / %s)!" % (handlers[GDBMIResultHandler.TAG].result_class, handlers[GDBMIResultHandler.TAG].result_str)) + logging.error("GDB/MI command failed (%s / %s)!" % (handlers[GDBMIResultHandler.TAG].result_class, handlers[GDBMIResultHandler.TAG].result_str)) return p loader = None @@ -974,7 +990,7 @@ def info_corefile(args): loader = ESPCoreDumpFlashLoader(args.off, port=args.port) core_fname = loader.create_corefile(args.save_core, rom_elf=rom_elf) if not core_fname: - print("Failed to create corefile!") + logging.error("Failed to create corefile!") loader.cleanup() return else: @@ -983,7 +999,7 @@ def info_corefile(args): loader = ESPCoreDumpFileLoader(core_fname, args.core_format == 'b64') core_fname = loader.create_corefile(args.save_core, rom_elf=rom_elf) if not core_fname: - print("Failed to create corefile!") + logging.error("Failed to create corefile!") loader.cleanup() return @@ -1111,6 +1127,7 @@ def main(): parser_debug_coredump = subparsers.add_parser( 'dbg_corefile', help='Starts GDB debugging session with specified corefile') + parser_debug_coredump.add_argument('--debug', '-d', help='Log level (0..3)', type=int, default=2) parser_debug_coredump.add_argument('--gdb', '-g', help='Path to gdb', default='xtensa-esp32-elf-gdb') parser_debug_coredump.add_argument('--core', '-c', help='Path to core dump file (if skipped core dump will be read from flash)', type=str) parser_debug_coredump.add_argument('--core-format', '-t', help='(elf, raw or b64). File specified with "-c" is an ELF ("elf"), raw (raw) or base64-encoded (b64) binary', type=str, default='elf') @@ -1122,6 +1139,7 @@ def main(): parser_info_coredump = subparsers.add_parser( 'info_corefile', help='Print core dump info from file') + parser_info_coredump.add_argument('--debug', '-d', help='Log level (0..3)', type=int, default=0) parser_info_coredump.add_argument('--gdb', '-g', help='Path to gdb', default='xtensa-esp32-elf-gdb') parser_info_coredump.add_argument('--core', '-c', help='Path to core dump file (if skipped core dump will be read from flash)', type=str) parser_info_coredump.add_argument('--core-format', '-t', help='(elf, raw or b64). File specified with "-c" is an ELF ("elf"), raw (raw) or base64-encoded (b64) binary', type=str, default='elf') @@ -1137,6 +1155,21 @@ def main(): args = parser.parse_args() + log_level = logging.CRITICAL + if args.debug == 0: + log_level = logging.CRITICAL + elif args.debug == 1: + log_level = logging.ERROR + elif args.debug == 2: + log_level = logging.WARNING + elif args.debug == 3: + log_level = logging.INFO + else: + log_level = logging.DEBUG + # logging.warning('Watch out!') # will print a message to the console + # logging.info('I told you so') # will not print anything + logging.basicConfig(format='%(levelname)s:%(message)s', level=log_level) + print('espcoredump.py v%s' % __version__) operation_func = globals()[args.operation] diff --git a/docs/en/api-guides/core_dump.rst b/docs/en/api-guides/core_dump.rst index 5b3a6e3c53..536d999efb 100644 --- a/docs/en/api-guides/core_dump.rst +++ b/docs/en/api-guides/core_dump.rst @@ -89,6 +89,7 @@ Generic command syntax: * info_corefile. Retrieve core dump and print useful info. * dbg_corefile. Retrieve core dump and start GDB session with it. :Command Arguments: + * --debug,-d DEBUG. Log level (0..3). * --gdb,-g GDB. Path to gdb to use for data retrieval. * --core,-c CORE. Path to core dump file to use (if skipped core dump will be read from flash). * --core-format,-t CORE_FORMAT. Specifies that file passed with "-c" is an ELF ("elf"), dumped raw binary ("raw") or base64-encoded ("b64") format.