From fb80c8b301e30ec77d1e644a4573822bd22cbdd2 Mon Sep 17 00:00:00 2001 From: Thomas Hebb Date: Fri, 12 Sep 2025 12:12:15 -0400 Subject: [PATCH 1/7] messages_live: New module, initial implementation for non-terse messages --- src/main.py | 9 ++ src/modules/messages_live.py | 205 +++++++++++++++++++++++++++++++++++ 2 files changed, 214 insertions(+) create mode 100644 src/modules/messages_live.py diff --git a/src/main.py b/src/main.py index 959b2da..c1029f8 100644 --- a/src/main.py +++ b/src/main.py @@ -13,6 +13,7 @@ from .modules.cli import CommandLineInterface from .modules.dlf_dump import DlfDumper from .modules.info import InfoRetriever +from .modules.messages_live import MessagePrinter from .modules._utils import FileType from .inputs.json_geo_read import JsonGeoReader @@ -72,6 +73,7 @@ def main(): modules.add_argument('--json-geo-dump', metavar = 'JSON_FILE', type = FileType('a'), help = 'Generate a JSON file containing both raw log frames and GPS coordinates, for further reprocessing. ' + 'To be used in combination with --adb.') modules.add_argument('--decoded-sibs-dump', action = 'store_true', help = 'Print decoded SIBs to stdout (experimental, requires pycrate).') + modules.add_argument('--messages-live', action = 'store_true', help = 'Print modem log messages to stdout.') pcap_options = parser.add_argument_group(title = 'PCAP generation options', description = 'To be used along with --pcap-dump or --wireshark-live.') @@ -84,6 +86,11 @@ def main(): memory_options.add_argument('--start', metavar = 'MEMORY_START', default = '00000000', help = 'Offset at which to start to dump memory (hex number), by default 00000000.') memory_options.add_argument('--stop', metavar = 'MEMORY_STOP', default = 'ffffffff', help = 'Offset at which to stop to dump memory (hex number), by default ffffffff.') + messages_options = parser.add_argument_group(title = 'Modem log options', description = 'To be used along with --messages-live.') + + messages_options.add_argument('--qdb', metavar = 'QSHRINK_DB', type = FileType('rb'), action = 'append', help = 'Optional QShrink database of terse message strings. If specified multiple times, later files take precedence.') + # TODO: subsystem argument? + args = parser.parse_args() basicConfig(stream = stderr, level = DEBUG if args.verbose else INFO, @@ -163,6 +170,8 @@ def parse_modules_args(args): diag_input.add_module(InfoRetriever(diag_input)) if args.dlf_dump: diag_input.add_module(DlfDumper(diag_input, args.dlf_dump)) + if args.messages_live: + diag_input.add_module(MessagePrinter(diag_input, args.qdb or [])) # if args.efs_dump: # raise NotImplementedError diff --git a/src/modules/messages_live.py b/src/modules/messages_live.py new file mode 100644 index 0000000..c97f67b --- /dev/null +++ b/src/modules/messages_live.py @@ -0,0 +1,205 @@ +#!/usr/bin/python3 +#-*- encoding: Utf-8 -*- +from collections import namedtuple +from logging import warning +from struct import Struct, pack # TODO: Clean up? + +from ..inputs._base_input import message_id_to_name, MSG_EXT_SUBCMD_SET_ALL_RT_MASKS + +from ..protocol.messages import * + +class ParseableStruct: + + @classmethod + def _parse(cls, data): + return cls._make(cls.STRUCT.unpack(data)) + + @classmethod + def _parse_start(cls, data): + parsed = cls._parse(data[:cls.STRUCT.size]) + remainder = data[cls.STRUCT.size:] + return parsed, remainder + + +# From https://github.com/osmocom/osmo-qcdiag/blob/5b01f0bedd70f0c0df589eba347a8580d510d737/src/protocol/protocol.h#L26-L33 +class MsgHeader(ParseableStruct, namedtuple('MsgHeader', ['ts_type', 'num_args', 'drop_cnt', 'timestamp'])): + STRUCT = Struct(' Date: Fri, 12 Sep 2025 15:26:24 -0400 Subject: [PATCH 2/7] messages_live: Put argument pretty-printing in its own function --- src/modules/messages_live.py | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/src/modules/messages_live.py b/src/modules/messages_live.py index c97f67b..02b57ea 100644 --- a/src/modules/messages_live.py +++ b/src/modules/messages_live.py @@ -89,9 +89,7 @@ def log_message(self, ssid, ss_mask, line, file, string, args): formatted = cprintf(string, args).decode('ascii', 'replace') except IndexError: fallback_string = string.decode('ascii', 'replace') - fallback_args = ', '.join(f'{int.from_bytes(arg, 'little', signed=False):#010x}' for arg in args) - - formatted = f'{fallback_string} ← [{fallback_args}]' + formatted = f'{fallback_string} ← {self.debug_args(args)}' # Replace newlines with a glyph so that each message appears on a single line formatted = formatted.replace('\n', '⏎') @@ -102,6 +100,12 @@ def log_message(self, ssid, ss_mask, line, file, string, args): print(f'[{ssid:5}] {line_spec:44} {formatted}') + @staticmethod + def debug_args(args): + values = ', '.join(f'{int.from_bytes(arg, 'little', signed=False):#010x}' for arg in args) + return f'[{values}]' + + PRINTF_FLAG = [b'#', b'0', b'-', b' ', b'+'] PRINTF_LENGTH = [b'hh', b'h', b'll', b'l', b'q', b'L', b'j', b'z', b'Z', b't'] PRINTF_CONV = [b'd', b'i', b'o', b'u', b'x', b'X', b'e', b'E', b'f', b'F', b'g', b'G', b'a', b'A', b'c', b's', b'p', b'%'] From ea59f6a67c66d8b31abdfe3c58feab4be96c03f8 Mon Sep 17 00:00:00 2001 From: Thomas Hebb Date: Fri, 12 Sep 2025 16:01:44 -0400 Subject: [PATCH 3/7] messages_live: Warn of dropped messages --- src/modules/messages_live.py | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/modules/messages_live.py b/src/modules/messages_live.py index 02b57ea..fff8ddf 100644 --- a/src/modules/messages_live.py +++ b/src/modules/messages_live.py @@ -73,6 +73,9 @@ def on_message(self, opcode, payload): hdr, data = MsgHeader._parse_start(payload) + if hdr.drop_cnt > 0: + warning(f"Dropped {hdr.drop_cnt} log message(s); consider adding filters") + if opcode == DIAG_EXT_MSG_F: meta, rest = NormalMeta._parse_start(data) args, rest = args_at_start(rest, 4, hdr.num_args) From e090823333f471746222e08dbd24d1039cf3e14c Mon Sep 17 00:00:00 2001 From: Thomas Hebb Date: Fri, 12 Sep 2025 15:27:19 -0400 Subject: [PATCH 4/7] messages_live: Support terse messages --- src/modules/messages_live.py | 152 ++++++++++++++++++++++++++++++++++- 1 file changed, 151 insertions(+), 1 deletion(-) diff --git a/src/modules/messages_live.py b/src/modules/messages_live.py index fff8ddf..3ba12a9 100644 --- a/src/modules/messages_live.py +++ b/src/modules/messages_live.py @@ -1,8 +1,12 @@ #!/usr/bin/python3 #-*- encoding: Utf-8 -*- from collections import namedtuple -from logging import warning +import io +from logging import warning, debug +import re from struct import Struct, pack # TODO: Clean up? +import uuid +import zlib from ..inputs._base_input import message_id_to_name, MSG_EXT_SUBCMD_SET_ALL_RT_MASKS @@ -28,6 +32,12 @@ class MsgHeader(ParseableStruct, namedtuple('MsgHeader', ['ts_type', 'num_args', class NormalMeta(ParseableStruct, namedtuple('NormalMeta', ['line', 'ssid', 'ss_mask'])): STRUCT = Struct('> 4) & 0xf + num_args = (hdr.num_args >> 0) & 0xf + args, _ = args_at_start(rest, arg_size, num_args) + + h = self.qdb.qsr4_messages.get(meta.hash) + if h is not None: + self.log_message(h.ssid, h.ss_mask, h.line, h.file, h.string, args) + else: + warning(f'Unmapped terse message (try --qdb): {meta.hash}{self.debug_args(args)}') else: warning(f'Unhandled message opcode {message_id_to_name.get(opcode, opcode)}') @@ -109,6 +144,89 @@ def debug_args(args): return f'[{values}]' +class QdbFile: + + HashedMessage = namedtuple('HashedMessage', ['hash', 'file', 'string']) + Qsr4HashedMessage = namedtuple('Qsr4HashedMessage', ['hash', 'ss_mask', 'ssid', 'line', 'file', 'string']) + + QDB_HEADER_SIZE = 0x40 + TAG_REGEX = re.compile(rb'<(\w+)>(?:\s*(.*?)\s*<[\\/]\1>)?\s*') + + + def __init__(self): + + self.messages = {} + self.qsr4_messages = {} + + + def parse(self, file): + + qdb_header = file.read(self.QDB_HEADER_SIZE) + if len(qdb_header) == self.QDB_HEADER_SIZE and qdb_header.startswith(b'\x7fQDB'): + # Compressed `.qdb` file + guid = uuid.UUID(bytes=qdb_header[4:20]) + debug(f'Detected compressed .qdb file with GUID {guid}') + + inner = io.BufferedReader(ZlibReader(file)) + parsed = self.parse_uncompressed(inner) + + # TODO: check GUID match + else: + # Not compressed, try to parse directly + file.seek(0) + parsed = self.parse_uncompressed(file) + + debug(f'Parsed QDB {parsed}') + return parsed + + + def parse_uncompressed(self, file): + + meta = {} + + cur_tag = None + expected_close = None + for line in file: + line = line.rstrip(b'\n') + if not line or line.startswith(b'#'): + continue + elif cur_tag is not None and line.rstrip() in expected_close: + cur_tag = None + expected_close = None + elif cur_tag is None and (match := self.TAG_REGEX.fullmatch(line)): + tag, singleline_content = match.groups() + if singleline_content is not None: + # Single-line tags contain file metadata + meta[tag] = singleline_content + else: + cur_tag = tag + expected_close = [rb'<\%s>' % cur_tag, rb'' % cur_tag] + else: + self.process_line(cur_tag, line) + + if cur_tag is not None: + raise ValueError('unclosed tag', cur_tag) + + return meta + + + def process_line(self, tag, line): + + if tag is None: + m = self.intify(self.HashedMessage, line.split(b':', 2), ('hash',)) + self.messages[m.hash] = m + elif tag == b'Content': + m = self.intify(self.Qsr4HashedMessage, line.split(b':', 5), ('hash', 'ss_mask', 'ssid', 'line')) + self.qsr4_messages[m.hash] = m + + + @staticmethod + def intify(tuple_type, tuple_values, to_convert): + + mapped = (int(v) if tuple_type._fields[i] in to_convert else v for i, v in enumerate(tuple_values)) + return tuple_type._make(mapped) + + PRINTF_FLAG = [b'#', b'0', b'-', b' ', b'+'] PRINTF_LENGTH = [b'hh', b'h', b'll', b'l', b'q', b'L', b'j', b'z', b'Z', b't'] PRINTF_CONV = [b'd', b'i', b'o', b'u', b'x', b'X', b'e', b'E', b'f', b'F', b'g', b'G', b'a', b'A', b'c', b's', b'p', b'%'] @@ -210,3 +328,35 @@ def take_repeated_tokens(tokens): raise IndexError('more arguments than format conversions') return result + + +class ZlibReader(io.RawIOBase): + + def __init__(self, raw): + + self.raw = raw + self.decompressor = zlib.decompressobj() + + + def readable(self): + + return True + + + def readinto(self, buf): + + if not len(buf): + return 0 + + compressed = self.decompressor.unconsumed_tail or self.raw.read(io.DEFAULT_BUFFER_SIZE) + decompressed = self.decompressor.decompress(compressed, len(buf)) + + buf[:len(decompressed)] = decompressed + return len(decompressed) + + + def close(self): + + self.decompressor = None + self.raw.close() + return super().close() From beb12a4d288a62458def22ecc97a8c25296a9d32 Mon Sep 17 00:00:00 2001 From: Thomas Hebb Date: Sat, 13 Sep 2025 12:28:44 -0400 Subject: [PATCH 5/7] messages_live: Print substituted argument values in bold --- src/main.py | 3 ++- src/modules/messages_live.py | 23 +++++++++++++++++------ 2 files changed, 19 insertions(+), 7 deletions(-) diff --git a/src/main.py b/src/main.py index c1029f8..510c626 100644 --- a/src/main.py +++ b/src/main.py @@ -89,6 +89,7 @@ def main(): messages_options = parser.add_argument_group(title = 'Modem log options', description = 'To be used along with --messages-live.') messages_options.add_argument('--qdb', metavar = 'QSHRINK_DB', type = FileType('rb'), action = 'append', help = 'Optional QShrink database of terse message strings. If specified multiple times, later files take precedence.') + messages_options.add_argument('--no-style', action = 'store_true', help = "Don't highlight argument values in bold even when a TTY is present.") # TODO: subsystem argument? args = parser.parse_args() @@ -171,7 +172,7 @@ def parse_modules_args(args): if args.dlf_dump: diag_input.add_module(DlfDumper(diag_input, args.dlf_dump)) if args.messages_live: - diag_input.add_module(MessagePrinter(diag_input, args.qdb or [])) + diag_input.add_module(MessagePrinter(diag_input, args.qdb or [], not args.no_style)) # if args.efs_dump: # raise NotImplementedError diff --git a/src/modules/messages_live.py b/src/modules/messages_live.py index 3ba12a9..f71706c 100644 --- a/src/modules/messages_live.py +++ b/src/modules/messages_live.py @@ -5,6 +5,7 @@ from logging import warning, debug import re from struct import Struct, pack # TODO: Clean up? +import sys import uuid import zlib @@ -60,10 +61,12 @@ def args_at_start(data, arg_size, num_args): class MessagePrinter: - def __init__(self, diag_input, qshrink_fds): + def __init__(self, diag_input, qshrink_fds, enable_style): self.diag_input = diag_input + self.enable_style = enable_style and sys.stdout.isatty() + self.qdb = QdbFile() for fd in qshrink_fds: self.qdb.parse(fd) @@ -124,10 +127,10 @@ def on_message(self, opcode, payload): def log_message(self, ssid, ss_mask, line, file, string, args): try: - formatted = cprintf(string, args).decode('ascii', 'replace') + formatted = cprintf(string, args, self.bold).decode('ascii', 'replace') except IndexError: fallback_string = string.decode('ascii', 'replace') - formatted = f'{fallback_string} ← {self.debug_args(args)}' + formatted = f'{fallback_string} ← {self.bold(self.debug_args(args))}' # Replace newlines with a glyph so that each message appears on a single line formatted = formatted.replace('\n', '⏎') @@ -138,6 +141,14 @@ def log_message(self, ssid, ss_mask, line, file, string, args): print(f'[{ssid:5}] {line_spec:44} {formatted}') + def bold(self, text): + + if self.enable_style: + return f'\x1b[1m{text}\x1b[0m' + else: + return text + + @staticmethod def debug_args(args): values = ', '.join(f'{int.from_bytes(arg, 'little', signed=False):#010x}' for arg in args) @@ -230,7 +241,7 @@ def intify(tuple_type, tuple_values, to_convert): PRINTF_FLAG = [b'#', b'0', b'-', b' ', b'+'] PRINTF_LENGTH = [b'hh', b'h', b'll', b'l', b'q', b'L', b'j', b'z', b'Z', b't'] PRINTF_CONV = [b'd', b'i', b'o', b'u', b'x', b'X', b'e', b'E', b'f', b'F', b'g', b'G', b'a', b'A', b'c', b's', b'p', b'%'] -def cprintf(fmt, args): +def cprintf(fmt, args, arg_styler=lambda x: x): result = bytearray() pos = 0 @@ -309,7 +320,7 @@ def take_repeated_tokens(tokens): py_conv = conv.decode('ascii') val = int.from_bytes(args.pop(), 'little', signed=signed) - formatted = f'%{py_flags}{py_width}{py_precision}{py_conv}' % val + formatted = arg_styler(f'%{py_flags}{py_width}{py_precision}{py_conv}' % val) result.extend(formatted.encode('ascii')) elif conv == b'%': @@ -320,7 +331,7 @@ def take_repeated_tokens(tokens): py_conv = conv.decode('ascii') val = int.from_bytes(args.pop(), 'little', signed=False) - formatted = f'%{py_conv}[{val:#010x}]' + formatted = arg_styler(f'%{py_conv}[{val:#010x}]') result.extend(formatted.encode('ascii')) From 0a5aedec9ec997b1b73fd2b57a6eeb5f10549748 Mon Sep 17 00:00:00 2001 From: Thomas Hebb Date: Sat, 13 Sep 2025 12:36:13 -0400 Subject: [PATCH 6/7] messages_live: Allow filtering to specific subsystems This doesn't currently allow sending a range of subsystem IDs, nor do we print the mask of each log message, making the mask piece of the argument difficult to determine. But it's a good start. --- src/inputs/_base_input.py | 1 + src/main.py | 14 ++++++++++++-- src/modules/messages_live.py | 11 ++++++++--- 3 files changed, 21 insertions(+), 5 deletions(-) diff --git a/src/inputs/_base_input.py b/src/inputs/_base_input.py index 51a67c0..a89ace6 100644 --- a/src/inputs/_base_input.py +++ b/src/inputs/_base_input.py @@ -15,6 +15,7 @@ LOG_CONFIG_DISABLE_OP = 0 +MSG_EXT_SUBCMD_SET_RT_MASK = 4 MSG_EXT_SUBCMD_SET_ALL_RT_MASKS = 5 MSG_LVL_NONE = 0 diff --git a/src/main.py b/src/main.py index 510c626..ebaef2c 100644 --- a/src/main.py +++ b/src/main.py @@ -88,9 +88,19 @@ def main(): messages_options = parser.add_argument_group(title = 'Modem log options', description = 'To be used along with --messages-live.') + def msg_filter(string): + parts = [int(x, 0) for x in string.split(':')] + if len(parts) == 1: + # Enable all mask bits + return [parts[0], 0xffffffff] + elif len(parts) == 2: + return parts + else: + raise ValueError('message filter must be in the format SUBSYS[:MASK]') + messages_options.add_argument('--qdb', metavar = 'QSHRINK_DB', type = FileType('rb'), action = 'append', help = 'Optional QShrink database of terse message strings. If specified multiple times, later files take precedence.') messages_options.add_argument('--no-style', action = 'store_true', help = "Don't highlight argument values in bold even when a TTY is present.") - # TODO: subsystem argument? + messages_options.add_argument('--msg-filter', metavar = 'SUBSYS[:MASK]', type = msg_filter, action = 'append', help = 'Enable messages for the given subsystem. Specify multiple times, or omit to show all messages.') args = parser.parse_args() @@ -172,7 +182,7 @@ def parse_modules_args(args): if args.dlf_dump: diag_input.add_module(DlfDumper(diag_input, args.dlf_dump)) if args.messages_live: - diag_input.add_module(MessagePrinter(diag_input, args.qdb or [], not args.no_style)) + diag_input.add_module(MessagePrinter(diag_input, args.qdb or [], args.msg_filter, not args.no_style)) # if args.efs_dump: # raise NotImplementedError diff --git a/src/modules/messages_live.py b/src/modules/messages_live.py index f71706c..6c165bd 100644 --- a/src/modules/messages_live.py +++ b/src/modules/messages_live.py @@ -9,7 +9,7 @@ import uuid import zlib -from ..inputs._base_input import message_id_to_name, MSG_EXT_SUBCMD_SET_ALL_RT_MASKS +from ..inputs._base_input import message_id_to_name, MSG_EXT_SUBCMD_SET_RT_MASK, MSG_EXT_SUBCMD_SET_ALL_RT_MASKS from ..protocol.messages import * @@ -61,10 +61,11 @@ def args_at_start(data, arg_size, num_args): class MessagePrinter: - def __init__(self, diag_input, qshrink_fds, enable_style): + def __init__(self, diag_input, qshrink_fds, msg_filters, enable_style): self.diag_input = diag_input + self.msg_filters = msg_filters self.enable_style = enable_style and sys.stdout.isatty() self.qdb = QdbFile() @@ -74,7 +75,11 @@ def __init__(self, diag_input, qshrink_fds, enable_style): def on_init(self): - self.diag_input.send_recv(DIAG_EXT_MSG_CONFIG_F, pack(' Date: Sat, 13 Sep 2025 13:44:07 -0400 Subject: [PATCH 7/7] messages_live: Stylistic cleanups --- src/modules/messages_live.py | 31 +++++++++++++++---------------- 1 file changed, 15 insertions(+), 16 deletions(-) diff --git a/src/modules/messages_live.py b/src/modules/messages_live.py index 6c165bd..dac359a 100644 --- a/src/modules/messages_live.py +++ b/src/modules/messages_live.py @@ -40,20 +40,6 @@ class Qsr4TerseMeta(ParseableStruct, namedtuple('Qsr4TerseMeta', ['hash', 'magic STRUCT = Struct('