• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1"""
2Command line tool to process minidump files and print what was logged by GfxApiLogger.
3
4For more details see:
5
6design: go/bstar-gfx-logging
7g3doc:  http://g3doc/play/g3doc/games/battlestar/kiwivm/graphics-tips.md#gfx-logs
8C++:    http://source/play-internal/battlestar/aosp/device/generic/vulkan-cereal/base/GfxApiLogger.h
9
10Usage:
11
12python3 print_gfx_logs.py <path to minidump file>
13"""
14
15import argparse
16import ctypes
17import sys
18from datetime import datetime
19import mmap
20import textwrap
21import command_printer
22from typing import NamedTuple, Optional, List
23import traceback
24
25
26class Header(ctypes.Structure):
27    """The C struct that we use to represent the data in memory
28    Keep in sync with GfxApiLogger.h
29    """
30    _fields_ = [('signature', ctypes.c_char * 10),
31                ('version', ctypes.c_uint16),
32                ('thread_id', ctypes.c_uint32),
33                ('last_written_time', ctypes.c_uint64),
34                ('write_index', ctypes.c_uint32),
35                ('committed_index', ctypes.c_uint32),
36                ('capture_id', ctypes.c_uint64),
37                ('data_size', ctypes.c_uint32)]
38
39
40class Command(NamedTuple):
41    """A single command in the stream"""
42    opcode: int
43    original_size: int
44    data: bytes
45
46
47class Stream(NamedTuple):
48    """Stream of commands received from the guest"""
49    pos_in_file: int  # Location of this stream in the minidump file, useful for debugging
50    timestamp: int  # Unix timestamp of last command received, in milliseconds
51    thread_id: int
52    capture_id: int
53    commands: List[Command]
54    error_message: Optional[str]  # `None` if there were no errors parsing this stream
55
56
57def read_uint32(buf: bytes, pos: int) -> int:
58    """Reads a single uint32 from buf at a given position"""
59    assert pos + 4 <= len(buf)
60    return int.from_bytes(buf[pos:pos + 4], byteorder='little', signed=False)
61
62
63def process_command(buf: bytes) -> Command:
64    opcode = read_uint32(buf, 0)
65    size = read_uint32(buf, 4)
66    return Command(opcode, size, bytes(buf[8:]))
67
68
69def process_stream(file_bytes: mmap, file_pos: int) -> Stream:
70    # Read the header
71    file_bytes.seek(file_pos)
72    header = Header()
73    header_bytes = file_bytes.read(ctypes.sizeof(header))
74    ctypes.memmove(ctypes.addressof(header), header_bytes, ctypes.sizeof(header))
75
76    if header.signature != b'GFXAPILOG':
77        return Stream(file_pos, error_message="Signature doesn't match")
78
79    if header.version != 2:
80        return Stream(file_pos, error_message=("This script can only process version 2 of the graphics API logs, " +
81                                               "but the dump file uses version {} ").format(data.version))
82
83    # Convert Windows' GetSystemTimeAsFileTime to Unix timestamp
84    # https://stackoverflow.com/questions/1695288/getting-the-current-time-in-milliseconds-from-the-system-clock-in-windows
85    timestamp_ms = int(header.last_written_time / 10000 - 11644473600000)
86    if timestamp_ms <= 0: timestamp_ms = 0
87
88    # Sanity check the size
89    if header.data_size > 5_000_000:
90        return Stream(file_pos,
91                      error_message="data size is larger than 5MB. This likely indicates garbage/corrupted data")
92
93    if header.committed_index >= header.data_size:
94        return Stream(file_pos,
95                      error_message="index is larger than buffer size. Likely indicates garbage/corrupted data")
96
97    file_bytes.seek(file_pos + ctypes.sizeof(header))
98    data = file_bytes.read(header.data_size)
99
100    # Reorder the buffer so that we can read it in a single pass from back to front
101    buf = data[header.committed_index:] + data[:header.committed_index]
102
103    commands = []
104    i = len(buf)
105    while i >= 4:
106        i -= 4
107        size = read_uint32(buf, i)
108        if size == 0 or size > i:
109            # We reached the end of the stream
110            break
111        cmd = process_command(buf[i - size:i])
112
113        commands.append(cmd)
114        i -= size
115
116    commands.reverse()  # so that they're sorted from oldest to most recent
117    return Stream(file_pos, timestamp_ms, header.thread_id, header.capture_id, commands, None)
118
119
120def process_minidump(dump_file: str) -> List[Stream]:
121    """
122    Extracts a list of commands streams from a minidump file
123    """
124    streams = []
125    with open(dump_file, "r+b") as f:
126        mm = mmap.mmap(f.fileno(), 0)
127        pos = 0
128        while True:
129            pos = mm.find(b'GFXAPILOG', pos + 1)
130            if pos == -1:
131                break
132            streams.append(process_stream(mm, pos))
133
134    return streams
135
136
137def main():
138    parser = argparse.ArgumentParser(description="""Command line tool to process crash reports and print out the
139    commands logged by GfxApiLogger""")
140    parser.add_argument('dump_file', help="Path to  minidump file")
141
142    args = parser.parse_args()
143    streams = process_minidump(args.dump_file)
144
145    streams.sort(key=lambda s: s.timestamp)
146
147    for stream_idx, stream in enumerate(streams):
148        print(textwrap.dedent("""
149                  =======================================================
150                  GfxApiLog command stream #{} at offset {} in dump
151                    - Timestamp: {}
152                    - Thread id: {}
153                    - Capture id: {}""".format(stream_idx, stream.pos_in_file,
154                                               datetime.fromtimestamp(stream.timestamp / 1000.0),
155                                               stream.thread_id,
156                                               stream.capture_id)))
157        if stream.error_message:
158            print("Could not decode stream. Error: ", stream.error_message)
159            continue
160
161        subdecode_size = 0
162        for cmd_idx, cmd in enumerate(stream.commands):
163            cmd_printer = command_printer.CommandPrinter(cmd.opcode, cmd.original_size, cmd.data, stream_idx, cmd_idx)
164
165            try:
166                cmd_printer.print_cmd()
167            except:
168                # Print stack trace and continue
169                traceback.print_exc(file=sys.stdout)
170
171            if subdecode_size > 0:
172                subdecode_size -= cmd.original_size
173                assert subdecode_size >= 0
174                if subdecode_size == 0:
175                    print("\n--- end of subdecode ---")
176
177            if cmd_printer.cmd_name() == "OP_vkQueueFlushCommandsGOOGLE":
178                assert subdecode_size == 0
179                subdecode_size = cmd.original_size - 36
180                print("\n--- start of subdecode, size = {} bytes ---".format(subdecode_size))
181
182
183if __name__ == '__main__':
184    main()
185