pw_system: Add no-rpc-logging option for console
- Add --rpc-logging and --no-rpc-logging options to pw-system-console
defaults to True. If False no rpc logging will be started.
- Better --serial-debug logging that shows 3 views of each read/write
event: bytes, characters and lines.
- Fix an exception in console table view if a log message has no extra
metadata.
Change-Id: Ibe507a6a7822c16c91aa36b832ca42d9c8b757b4
Reviewed-on: https://pigweed-review.googlesource.com/c/pigweed/pigweed/+/109613
Pigweed-Auto-Submit: Anthony DiGirolamo <tonymd@google.com>
Reviewed-by: Erik Gilling <konkers@google.com>
Commit-Queue: Auto-Submit <auto-submit@pigweed.google.com.iam.gserviceaccount.com>
diff --git a/pw_console/py/pw_console/pyserial_wrapper.py b/pw_console/py/pw_console/pyserial_wrapper.py
index ac00e05..072d5e4 100644
--- a/pw_console/py/pw_console/pyserial_wrapper.py
+++ b/pw_console/py/pw_console/pyserial_wrapper.py
@@ -24,7 +24,7 @@
_LOG = logging.getLogger('pw_console.serial_debug_logger')
-def _log_hex_strings(data, prefix=''):
+def _log_hex_strings(data: bytes, prefix=''):
"""Create alinged hex number and character view log messages."""
# Make a list of 2 character hex number strings.
hex_numbers = textwrap.wrap(data.hex(), 2)
@@ -51,12 +51,14 @@
hex_numbers_msg,
extra=dict(extra_metadata_fields={
'msg': hex_numbers_msg,
+ 'view': 'hex',
}))
_LOG.debug('%s%s',
prefix,
hex_chars_msg,
extra=dict(extra_metadata_fields={
'msg': hex_chars_msg,
+ 'view': 'chars',
}))
@@ -87,16 +89,28 @@
_LOG.debug('%s%s',
prefix,
data,
- extra=dict(extra_metadata_fields={
- 'mode': 'Read',
- 'bytes': len(data),
- 'msg': str(data),
- }))
+ extra=dict(
+ extra_metadata_fields={
+ 'mode': 'Read',
+ 'bytes': len(data),
+ 'view': 'bytes',
+ 'msg': str(data),
+ }))
_log_hex_strings(data, prefix=prefix)
+ # Print individual lines
+ for line in data.decode(encoding='utf-8',
+ errors='ignore').splitlines():
+ _LOG.debug('%s',
+ line,
+ extra=dict(extra_metadata_fields={
+ 'msg': line,
+ 'view': 'lines',
+ }))
+
return data
- def write(self, data, *args, **kwargs):
+ def write(self, data: bytes, *args, **kwargs):
self.pw_bps_history['write'].log(len(data))
self.pw_bps_history['total'].log(len(data))
@@ -105,11 +119,23 @@
_LOG.debug('%s%s',
prefix,
data,
- extra=dict(extra_metadata_fields={
- 'mode': 'Write',
- 'bytes': len(data),
- 'msg': str(data)
- }))
+ extra=dict(
+ extra_metadata_fields={
+ 'mode': 'Write',
+ 'bytes': len(data),
+ 'view': 'bytes',
+ 'msg': str(data)
+ }))
_log_hex_strings(data, prefix=prefix)
+ # Print individual lines
+ for line in data.decode(encoding='utf-8',
+ errors='ignore').splitlines():
+ _LOG.debug('%s',
+ line,
+ extra=dict(extra_metadata_fields={
+ 'msg': line,
+ 'view': 'lines',
+ }))
+
super().write(data, *args, **kwargs)
diff --git a/pw_console/py/pw_console/widgets/table.py b/pw_console/py/pw_console/widgets/table.py
index 882a0dd..ec863f5 100644
--- a/pw_console/py/pw_console/widgets/table.py
+++ b/pw_console/py/pw_console/widgets/table.py
@@ -94,8 +94,14 @@
return ordered_columns.items()
- def update_metadata_column_widths(self, log: LogLine):
+ def update_metadata_column_widths(self, log: LogLine) -> None:
"""Calculate the max widths for each metadata field."""
+ if log.metadata is None:
+ log.update_metadata()
+ # If extra fields still don't exist, no need to update column widths.
+ if log.metadata is None:
+ return
+
for field_name, value in log.metadata.fields.items():
value_string = str(value)
diff --git a/pw_system/py/pw_system/console.py b/pw_system/py/pw_system/console.py
index fc20df1..6a9fbf9 100644
--- a/pw_system/py/pw_system/console.py
+++ b/pw_system/py/pw_system/console.py
@@ -161,6 +161,11 @@
dest='use_ipython',
help='Use IPython instead of pw_console.')
+ parser.add_argument('--rpc-logging',
+ action=argparse.BooleanOptionalAction,
+ default=True,
+ help='Use pw_rpc based logging.')
+
return parser.parse_args()
@@ -292,6 +297,7 @@
verbose: bool = False,
compiled_protos: Optional[List[ModuleType]] = None,
merge_device_and_host_logs: bool = False,
+ rpc_logging: bool = True,
use_ipython: bool = False) -> int:
"""Starts an interactive RPC console for HDLC."""
# argparse.FileType doesn't correctly handle '-' for binary files.
@@ -370,7 +376,8 @@
# Append compiled log.proto library to avoid include errors when manually
# provided, and shadowing errors due to ordering when the default global
# search path is used.
- compiled_protos.append(log_pb2)
+ if rpc_logging:
+ compiled_protos.append(log_pb2)
compiled_protos.append(unit_test_pb2)
protos.extend(compiled_protos)
protos.append(metric_service_pb2)
@@ -424,7 +431,8 @@
protos,
detokenizer,
timestamp_decoder=timestamp_decoder,
- rpc_timeout_s=5)
+ rpc_timeout_s=5,
+ use_rpc_logging=rpc_logging)
_start_python_terminal(
device=device_client,
diff --git a/pw_system/py/pw_system/device.py b/pw_system/py/pw_system/device.py
index f80aa04..a8bd580 100644
--- a/pw_system/py/pw_system/device.py
+++ b/pw_system/py/pw_system/device.py
@@ -49,7 +49,8 @@
proto_library: List[Union[ModuleType, Path]],
detokenizer: Optional[detokenize.Detokenizer],
timestamp_decoder: Optional[Callable[[int], str]],
- rpc_timeout_s=5):
+ rpc_timeout_s: float = 5,
+ use_rpc_logging: bool = True):
self.channel_id = channel_id
self.protos = proto_library
self.detokenizer = detokenizer
@@ -64,15 +65,27 @@
default_unary_timeout_s=self.rpc_timeout_s,
default_stream_timeout_s=None,
)
- self.client = HdlcRpcClient(
- read,
- self.protos,
- default_channels(write),
- lambda data: self.logger.info("%s", str(data)),
- client_impl=callback_client_impl)
- # Start listening to logs as soon as possible.
- self.listen_to_log_stream()
+ def detokenize_and_log_output(data: bytes, _detokenizer=None):
+ log_messages = data.decode(encoding='utf-8',
+ errors='surrogateescape')
+
+ if self.detokenizer:
+ log_messages = decode_optionally_tokenized(
+ self.detokenizer, data)
+
+ for line in log_messages.splitlines():
+ self.logger.info(line)
+
+ self.client = HdlcRpcClient(read,
+ self.protos,
+ default_channels(write),
+ detokenize_and_log_output,
+ client_impl=callback_client_impl)
+
+ if use_rpc_logging:
+ # Start listening to logs as soon as possible.
+ self.listen_to_log_stream()
def info(self) -> console_tools.ClientInfo:
return console_tools.ClientInfo('device', self.rpcs,
@@ -137,12 +150,12 @@
decode_optionally_tokenized(self.detokenizer,
log_proto.message))
else:
- message = log_proto.message.decode("utf-8")
+ message = log_proto.message.decode('utf-8')
log = pw_log_tokenized.FormatStringWithMetadata(message)
# Handle dropped count.
if log_proto.dropped:
- drop_reason = log_proto.message.decode("utf-8").lower(
+ drop_reason = log_proto.message.decode('utf-8').lower(
) if log_proto.message else 'enqueue failure on device'
self._handle_log_drop_count(log_proto.dropped, drop_reason)
continue
