[crashlog] Implement parser for JSON encoded crashlogs

[JDevlieghere]

Summary

Add a parser for JSON crashlogs. The CrashLogParser now defers to either the JSONCrashLogParser or the TextCrashLogParser. It first tries to interpret the input as JSON, and if that fails falling back to the textual parser.

[clayborg]

JSON crash logs are almost here??? I remember asking for those back when I was at Apple! Great news.

It would be nice to have a crash log from a small but real process we might be able to load as an end to end test?

lldb/examples/python/crashlog.py

413–414

you ok with this raising throwing an exception when/if these key/value pairs are not in the file?

[JDevlieghere]

In D91130#2387390, @clayborg wrote:

JSON crash logs are almost here??? I remember asking for those back when I was at Apple! Great news.

Yep! 🥳

It would be nice to have a crash log from a small but real process we might be able to load as an end to end test?

I'd be happy to, but is there a way to test the crashlog script without having a dsymForUUID?

lldb/examples/python/crashlog.py

413–414

Yeah, at least initially. It appears the format is still not locked down, so I hope this will give us more signal when things end up changing. But good point, long term we should be more defensive.

[clayborg]

In D91130#2387692, @JDevlieghere wrote:

In D91130#2387390, @clayborg wrote:

JSON crash logs are almost here??? I remember asking for those back when I was at Apple! Great news.

Yep! 🥳

Nice!

It would be nice to have a crash log from a small but real process we might be able to load as an end to end test?

I'd be happy to, but is there a way to test the crashlog script without having a dsymForUUID?

Yes, it would still load it up correctly and just show you the stack frame that are in the JSON format. The only reason you need dsymForUUID is to expand inline frames and add source file and line info if it isn't already in the crash log. So the test would test that it can parse the JSON format correctly and display what is already in the crash log without needing to actually re-symbolicate. "crashlog" doesn't assume it will be able to find symbols for all images. It will keep the string from the crashlog file that describes the address:

Thread 0:: CrBrowserMain  Dispatch queue: com.apple.main-thread
0   libsystem_kernel.dylib        	0x00007fff678a2dfa mach_msg_trap + 10
1   libsystem_kernel.dylib        	0x00007fff678a3170 mach_msg + 60
2   com.apple.CoreFoundation      	0x00007fff2d6f4ef5 __CFRunLoopServiceMachPort + 247
3   com.apple.CoreFoundation      	0x00007fff2d6f39c2 __CFRunLoopRun + 1319
4   com.apple.CoreFoundation      	0x00007fff2d6f2e3e CFRunLoopRunSpecific + 462
5   com.apple.HIToolbox           	0x00007fff2c31fabd RunCurrentEventLoopInMode + 292
6   com.apple.HIToolbox           	0x00007fff2c31f7d5 ReceiveNextEventCommon + 584
7   com.apple.HIToolbox           	0x00007fff2c31f579 _BlockUntilNextEventMatchingListInModeWithFilter + 64
8   com.apple.AppKit              	0x00007fff2a965039 _DPSNextEvent + 883
9   com.apple.AppKit              	0x00007fff2a963880 -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 1352
10  com.apple.AppKit              	0x00007fff2a95558e -[NSApplication run] + 658
11  com.apple.AppKit              	0x00007fff2a927396 NSApplicationMain + 777
12  com.sketchup.SketchUp.2017    	0x000000010a62638c main + 144
13  libdyld.dylib                 	0x00007fff67761cc9 start + 1

So for the first frame here from the text based crash log it would keep "mach_msg_trap + 10" in case it can't symbolicate any better.

[jasonmolenda]

You could also make a fakey dsymForUUID script like we do in some other corefile tests. Compile a C file with foo(), bar(), baz(), substitute the addresses of those symbols from the binary into the crashlog.json, substitute the UUID of the compiled program in the crashlog.json, then the fakey-dsymForUUID finds the binary, lldb loads it at the binary at the correct offset. It's a lot of futzing around, but it would be possible.

[clayborg]

In D91130#2389831, @jasonmolenda wrote:

You could also make a fakey dsymForUUID script like we do in some other corefile tests. Compile a C file with foo(), bar(), baz(), substitute the addresses of those symbols from the binary into the crashlog.json, substitute the UUID of the compiled program in the crashlog.json, then the fakey-dsymForUUID finds the binary, lldb loads it at the binary at the correct offset. It's a lot of futzing around, but it would be possible.

Crash logs can be loaded on other machines as well. Nothing stopping the test from running on linux, windows, or other systems. The main thing we want to test is if the JSON format creates the right objects with the right info

[jasonmolenda]

In D91130#2389867, @clayborg wrote:

Crash logs can be loaded on other machines as well. Nothing stopping the test from running on linux, windows, or other systems. The main thing we want to test is if the JSON format creates the right objects with the right info

Yeah, fakey-dsymForUUID isn't necessary. You compile a userland C program, grab the addresses of a few of its functions, substitute them & the UUID into the crashlog.json, then create an SBTarget with the compiled program and run the crashlog.json and test that it slid the binary & prints the right backtrace or whatever.

[jasonmolenda]

I guess the register context part of the crashlog.json would be the most architecture-dependent, but I bet crashlog.json doesn't use any of that when printing the backtrace -- it only uses the stack trace's pc values. So you could have a "x86_64" crashlog.json, build an arm64e userland program, substitute in the slide-adjusted values of a few functions and the UUID and it would load & symbolicate in lldb.

[JDevlieghere]

Add tests for JSON and text format

[clayborg]

Thanks for adding the extra tests!

lldb/examples/python/crashlog.py

 import plistlib
 import re
 import shlex
 import string
 import subprocess
 import sys
 import time
 import uuid
+import json
 
 try:
     # First try for LLDB in case PYTHONPATH is already correctly setup.
     import lldb
 except ImportError:
     # Ask the command line driver for the path to the lldb module. Copy over
     # the environment so that SDKROOT is propagated to xcrun.
     env = os.environ.copy()
def create_target(self):
             print('       Try loading the executable into lldb before running crashlog')
             print('       and/or make sure the .dSYM bundles can be found by Spotlight.')
         return self.target
 
     def get_target(self):
         return self.target
 
 
+class CrashLogFormatException(Exception):
+    pass
+
+
+class CrashLogParser:
+    def parse(self, debugger, path, verbose):
+        try:
+            return JSONCrashLogParser(debugger, path, verbose).parse()
+        except CrashLogFormatException:
+            return TextCrashLogParser(debugger, path, verbose).parse()
+
+
+class JSONCrashLogParser:
+    def __init__(self, debugger, path, verbose):
+        self.path = os.path.expanduser(path)
+        self.verbose = verbose
+        self.crashlog = CrashLog(debugger, self.path, self.verbose)
+
+    def parse(self):
+        with open(self.path, 'r') as f:
+            buffer = f.read()
+
+        # First line is meta-data.
+        buffer = buffer[buffer.index('\n') + 1:]
+
+        try:
+            self.data = json.loads(buffer)
+        except ValueError:
+            raise CrashLogFormatException()
+
+        self.parse_process_info(self.data)
+        self.parse_images(self.data['usedImages'])
+        self.parse_threads(self.data['threads'])
+
+        thread = self.crashlog.threads[self.crashlog.crashed_thread_idx]
+        thread.reason = self.parse_crash_reason(self.data['exception'])
+        thread.registers = self.parse_thread_registers(self.data['threadState'])
+
+        return self.crashlog
+
+    def get_image_extra_info(self, idx):
+        return self.data['legacyInfo']['imageExtraInfo'][idx]
+
+    def get_used_image(self, idx):
+        return self.data['usedImages'][idx]
+
+    def parse_process_info(self, json_data):
+        self.crashlog.process_id = json_data['pid']
+        self.crashlog.process_identifier = json_data['procName']
+        self.crashlog.process_path = json_data['procPath']
+
+    def parse_crash_reason(self, json_exception):
+        exception_type = json_exception['type']
+        exception_signal = json_exception['signal']
+        if 'codes' in json_exception:
+            exception_extra = " ({})".format(json_exception['codes'])
+        elif 'subtype' in json_exception:
+            exception_extra = " ({})".format(json_exception['subtype'])
+        else:
+            exception_extra = ""
+        return "{} ({}){}".format(exception_type, exception_signal,
+                                            exception_extra)
+
+    def parse_images(self, json_images):
+        idx = 0
+        for json_images in json_images:
+            img_uuid = uuid.UUID(json_images[0])
+            low = int(json_images[1])
+            high = 0
+            extra_info = self.get_image_extra_info(idx)
+            name = extra_info['name']
+            path = extra_info['path']
+            version = ""
+            darwin_image = self.crashlog.DarwinImage(low, high, name, version,
+                                                     img_uuid, path,
+                                                     self.verbose)
+            self.crashlog.images.append(darwin_image)
+            idx += 1
+
+    def parse_frames(self, thread, json_frames):
+        idx = 0
+        for json_frame in json_frames:
+            image_id = int(json_frame[0])
+
+            ident = self.get_image_extra_info(image_id)['name']
+            thread.add_ident(ident)
+            if ident not in self.crashlog.idents:
+                self.crashlog.idents.append(ident)
+
+            frame_offset = int(json_frame[1])
+            image = self.get_used_image(image_id)
+            image_addr = int(image[1])
+            pc = image_addr + frame_offset
+            thread.frames.append(self.crashlog.Frame(idx, pc, frame_offset))
+            idx += 1
+
+    def parse_threads(self, json_threads):
+        idx = 0
+        for json_thread in json_threads:
+            thread = self.crashlog.Thread(idx, False)
+            if json_thread.get('triggered', False):
+                self.crashlog.crashed_thread_idx = idx
+            thread.queue = json_thread.get('queue')
+            self.parse_frames(thread, json_thread.get('frames', []))
+            self.crashlog.threads.append(thread)
+            idx += 1
+
+    def parse_thread_registers(self, json_thread_state):
+        idx = 0
+        registers = dict()
+        for reg in json_thread_state.get('x', []):
+            key = str('x{}'.format(idx))
+            value = int(reg)
+            registers[key] = value
+            idx += 1
+
+        for register in ['lr', 'cpsr', 'fp', 'sp', 'esr', 'pc']:
+            if register in json_thread_state:
+                registers[register] = int(json_thread_state[register])
+
+        return registers
+
+
 class CrashLogParseMode:
     NORMAL = 0
     THREAD = 1
     IMAGES = 2
     THREGS = 3
     SYSTEM = 4
     INSTRS = 5
 
 
-class CrashLogParser:
+class TextCrashLogParser:
     parent_process_regex = re.compile('^Parent Process:\s*(.*)\[(\d+)\]')
     thread_state_regex = re.compile('^Thread ([0-9]+) crashed with')
     thread_instrs_regex = re.compile('^Thread ([0-9]+) instruction stream')
     thread_regex = re.compile('^Thread ([0-9]+)([^:]*):(.*)')
     app_backtrace_regex = re.compile('^Application Specific Backtrace ([0-9]+)([^:]*):(.*)')
     version = r'(\(.+\)|(arm|x86_)[0-9a-z]+)\s+'
     frame_regex = re.compile(r'^([0-9]+)' r'\s'                # id
                              r'+(.+?)'    r'\s+'               # img_name
def interactive_crashlogs(debugger, options, args):
     crash_log_files = list()
     for arg in args:
         for resolved_path in glob.glob(arg):
             crash_log_files.append(resolved_path)
 
     crash_logs = list()
     for crash_log_file in crash_log_files:
         try:
-            crash_log = CrashLogParser(debugger, crash_log_file, options.verbose).parse()
+            crash_log = CrashLogParser().parse(debugger, crash_log_file, options.verbose)
         except Exception as e:
             print(e)
             continue
         if options.debug:
             crash_log.dump()
         if not crash_log.images:
             print('error: no images in crash log "%s"' % (crash_log))
             continue
if options.debug_delay > 0:
         time.sleep(options.debug_delay)
     error = lldb.SBError()
 
     if args:
         if options.interactive:
             interactive_crashlogs(debugger, options, args)
         else:
             for crash_log_file in args:
-                crash_log_parser = CrashLogParser(debugger, crash_log_file, options.verbose)
-                crash_log = crash_log_parser.parse()
+                crash_log = CrashLogParser().parse(debugger, crash_log_file, options.verbose)
                 SymbolicateCrashLog(crash_log, options)
 if __name__ == '__main__':
     # Create a new debugger instance
     debugger = lldb.SBDebugger.Create()
     SymbolicateCrashLogs(debugger, sys.argv[1:])
     lldb.SBDebugger.Destroy(debugger)
 elif getattr(lldb, 'debugger', None):
     lldb.debugger.HandleCommand(
         'command script add -f lldb.macosx.crashlog.Symbolicate crashlog')
     lldb.debugger.HandleCommand(
         'command script add -f lldb.macosx.crashlog.save_crashlog save_crashlog')

lldb/test/Shell/ScriptInterpreter/Python/Crashlog/Inputs/Assertion.check

+# CHECK-NOT: AssertionError

lldb/test/Shell/ScriptInterpreter/Python/Crashlog/crashlog.test

 #                                                                 -*- python -*-
 # DEBUG: cd %S/../../../../../examples/python && cat %s | %lldb && false
 # RUN: cd %S/../../../../../examples/python && cat %s | %lldb | FileCheck %s
 # CHECK-LABEL: {{S}}KIP BEYOND CHECKS
 script
 import crashlog
-crash_log_parser = crashlog.CrashLogParser
+crash_log_parser = crashlog.TextCrashLogParser
 crash_log = crashlog.CrashLog
 images = [
 "0x10b60b000 - 0x10f707fff com.apple.LLDB.framework (1.1000.11.38.2 - 1000.11.38.2) <96E36F5C-1A83-39A1-8713-5FDD9701C3F1> /Applications/Xcode.app/Contents/SharedFrameworks/LLDB.framework/LLDB",
 # CHECK: 0x10b60b000
 # CHECK: 0x10f707fff
 # CHECK: com.apple.LLDB.framework
 # CHECK: 96E36F5C-1A83-39A1-8713-5FDD9701C3F1
 # CHECK: /Applications/Xcode.app/Contents/SharedFrameworks/LLDB.framework/LLDB

lldb/test/Shell/ScriptInterpreter/Python/Crashlog/json_parser.test

+#                                                                 -*- python -*-
+# RUN: cd %S/../../../../../examples/python && cat %s | %lldb 2>&1 > %t.out
+# RUN: cat %t.out | FileCheck %S/Inputs/Assertion.check
+script
+import crashlog
+import json
+
+parser = crashlog.JSONCrashLogParser("", "", False)
+
+process_info_json = json.loads('{"pid" : 287, "procName" : "mediaserverd", "procPath" : "\/usr\/sbin\/mediaserverd"}')
+parser.parse_process_info(process_info_json)
+
+assert parser.crashlog.process_id == 287
+assert parser.crashlog.process_identifier == "mediaserverd"
+assert parser.crashlog.process_path == "/usr/sbin/mediaserverd"
+
+crash_reason_json = json.loads('{"type" : "EXC_BAD_ACCESS", "signal" : "SIGSEGV", "subtype" : "KERN_INVALID_ADDRESS"}')
+assert parser.parse_crash_reason(crash_reason_json) == "EXC_BAD_ACCESS (SIGSEGV) (KERN_INVALID_ADDRESS)"
+
+crash_reason_json = json.loads('{"type" : "EXC_BAD_ACCESS", "signal" : "SIGSEGV"}')
+assert parser.parse_crash_reason(crash_reason_json) == "EXC_BAD_ACCESS (SIGSEGV)"
+
+crash_reason_json = json.loads('{"type" : "EXC_BAD_ACCESS", "signal" : "SIGSEGV", "codes" : "0x0000000000000000, 0x0000000000000000"}')
+assert parser.parse_crash_reason(crash_reason_json) == "EXC_BAD_ACCESS (SIGSEGV) (0x0000000000000000, 0x0000000000000000)"
+
+thread_state_json = json.loads('{"x":[268451845,117442566],"lr":7309751904,"cpsr":1073741824,"fp":6093236784,"sp":6093236704,"esr":1442840704,"pc":7309755088}')
+registers = parser.parse_thread_registers(thread_state_json)
+assert registers['x0'] == 268451845
+assert registers['x1'] == 117442566
+assert registers['lr'] == 7309751904
+assert registers['cpsr'] ==1073741824
+assert registers['fp'] == 6093236784
+assert registers['sp'] == 6093236704
+assert registers['esr'] == 1442840704
+assert registers['pc'] == 7309755088
+
+parser.data = json.loads('{"usedImages":[["f4d85377-f215-3da3-921e-3fe870e622e9",7309737984,"P"]],"legacyInfo":{"imageExtraInfo":[{"size":204800,"arch":"arm64e","path":"/usr/lib/system/libsystem_kernel.dylib","name":"libsystem_kernel.dylib"}]}}')
+thread_json = json.loads('[{"triggered":true,"id":3835,"queue":"com.apple.bwgraph.devicevendor","frames":[[0,101472],[0,408892]]}]')
+parser.parse_threads(thread_json)
+assert len(parser.crashlog.threads) == 1
+assert parser.crashlog.threads[0].queue == "com.apple.bwgraph.devicevendor"
+assert len(parser.crashlog.threads[0].frames) == 2
+assert parser.crashlog.threads[0].frames[0].pc == 7309839456
+assert parser.crashlog.threads[0].frames[0].description == 101472
+exit()