alex/esp-idf
alex/esp-idf
1
0
Fork 0
mirror of https://github.com/espressif/esp-idf.git synced 2024-10-05 20:47:46 -04:00
Code Issues Actions 2 Packages Projects Releases Wiki Activity

idf_monitor: add support for filtering options

Browse Source
This commit is contained in:
Roland Dobai 2018-05-30 15:35:50 +02:00
parent b2ff235bd0
commit 51e42d8e92
3 changed files with 224 additions and 26 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
components/esptool_py/Makefile.projbuild
View File

@ -85,7 +85,9 @@ endif
simple_monitor: $(call prereq_if_explicit,%flash)
$(MONITOR_PYTHON) -m serial.tools.miniterm --rts 0 --dtr 0 --raw $(ESPPORT) $(MONITORBAUD)
MONITOR_OPTS := --baud $(MONITORBAUD) --port $(ESPPORT) --toolchain-prefix $(CONFIG_TOOLPREFIX) --make "$(MAKE)"
PRINT_FILTER ?=
MONITOR_OPTS := --baud $(MONITORBAUD) --port $(ESPPORT) --toolchain-prefix $(CONFIG_TOOLPREFIX) --make "$(MAKE)" --print_filter "$(PRINT_FILTER)"
monitor: $(call prereq_if_explicit,%flash)
$(summary) MONITOR

84
docs/en/get-started/idf-monitor.rst
View File

@ -105,6 +105,90 @@ Sometimes you may want to stop new output printed to screen, to see the log befo
toggle the display (discard all serial data when the display is off) so that you can stop to see the log, and revert
again quickly without quitting the monitor.
Filtering the Output
====================
The IDF monitor can be invoked as ``make monitor PRINT_FILTER=""`` with
specifying a custom ``PRINT_FILTER`` option for filtering outputs. The default
value is an empty string which means that everything will be printed.
Restrictions on what to print can be specified as a series of
``<tag>:<log_level>`` items where ``<tag>`` is the tag string and
``<log_level>`` is a character from set ``{N, E, W, I, D, V, *}`` referring to
a level for :doc:`logging <../../api-reference/system/log>`. For example,
``PRINT_FILTER="tag1:W"`` will match and print (only) the outputs written with
``ESP_LOGW("tag1", ...)`` or at lower verbosity level, i.e. ``ESP_LOGE("tag1",
...)``. Not specifying a
``<log_level>`` or using ``*`` defaults to Verbose level.
.. note::
The primary logging is set up at compilation time through the
:doc:`logging library<../../api-reference/system/log>`.
Output filtering by the IDF monitor is only a secondary solution because
one cannot filter something which has been disabled at compilation time.
The advantage of the secondary filtering is that one can use various
filtering options without recompiling the application.
A restriction applies to tags when one wants to use them together with output
filtering: they cannot contain spaces, asterisks ``*`` and semicolons ``:``.
If the last line of the output is written without an end of line then the
output filtering might get confused, i.e. the monitor starts to print the line and only
later finds out that the line should have not been written. This is a known
issue and can be avoided by always adding an end of line after printing
something (especially when no output follows immediately afterwards).
Examples Of Filtering Rules:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~
- Asterisk can be used to match any tags. However, specifying
``PRINT_FILTER="*:I tag1:E"`` will print for ``tag1`` only errors because
the rule for ``tag1`` has a precedence over the rule for ``*``.
- The default (empty) rule is equivalent to ``*:V`` because matching every tag
at level Verbose or lower means matching everything.
- Rule ``"tag1:W tag1:E"`` is equivalent to ``"tag1:E"`` because any
consequent occurrence of the same tag name overwrites the previous one.
- Rule ``"tag1:I tag2:W"`` will print only ``tag1`` at verbosity level Info or
lower and ``tag2`` at verbosity level Warning or lower.
- Rule ``"tag1:I tag2:W tag3:N"`` is essentially equivalent to the previous
one because ``tag3:N`` specifies that ``tag3`` should not be printed.
- ``tag3:N`` in rule ``"tag1:I tag2:W tag3:N *:V"`` is more meaningful because
in this context the result will be that ``tag3`` will not be printed,
``tag1`` and ``tag2`` will be at the specified (or lower) verbosity level
and everything else will be printed by default.
- ``"*:N"`` will suppress all outputs even prints made by something else than
the logging functions, e.g. ``printf``. For printing those outputs one need
to use ``*:E`` or higher verbosity level.
- Rules ``"tag1:V"``, ``"tag1:v"``, ``"tag1:"``, ``"tag1:*"`` and ``"tag1"``
are all equivalent ones.
A More Complex Filtering Example
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
The following log snippet was acquired using ``make monitor``::
load:0x40078000,len:13564
entry 0x40078d4c
E (31) esp_image: image at 0x30000 has invalid magic byte
W (31) esp_image: image at 0x30000 has invalid SPI mode 255
E (39) boot: Factory app partition is not bootable
I (568) cpu_start: Pro cpu up.
I (569) heap_init: Initializing. RAM available for dynamic allocation:
I (603) cpu_start: Pro cpu start user code
D (309) light_driver: [light_init, 74]:status: 1, mode: 2
D (318) vfs: esp_vfs_register_fd_range is successful for range <54; 64) and VFS ID 1
I (328) wifi: wifi driver task: 3ffdbf84, prio:23, stack:4096, core=0
The captured output for ``make monitor PRINT_FILTER="wifi esp_image:E light_driver:I"`` is the following::
E (31) esp_image: image at 0x30000 has invalid magic byte
I (328) wifi: wifi driver task: 3ffdbf84, prio:23, stack:4096, core=0
``make monitor PRINT_FILTER="light_driver:D esp_image:N boot:N cpu_start:N vfs:N wifi:N *:V"`` gives the following output::
load:0x40078000,len:13564
entry 0x40078d4c
I (569) heap_init: Initializing. RAM available for dynamic allocation:
D (309) light_driver: [light_init, 74]:status: 1, mode: 2
Simple Monitor
==============

162
tools/idf_monitor.py
View File

@ -59,7 +59,7 @@ CTRL_Y = '\x19'
CTRL_P = '\x10'
CTRL_RBRACKET = '\x1d' # Ctrl+]
# ANSI terminal codes
# ANSI terminal codes (if changed, regular expressions in LineMatcher need to be udpated)
ANSI_RED = '\033[1;31m'
ANSI_YELLOW = '\033[0;33m'
ANSI_NORMAL = '\033[0m'
@ -74,17 +74,20 @@ def yellow_print(message):
def red_print(message):
color_print(message, ANSI_RED)
__version__ = "1.0"
__version__ = "1.1"
# Tags for tuples in queues
TAG_KEY = 0
TAG_SERIAL = 1
TAG_SERIAL_FLUSH = 2
# regex matches an potential PC value (0x4xxxxxxx)
MATCH_PCADDR = re.compile(r'0x4[0-9a-f]{7}', re.IGNORECASE)
DEFAULT_TOOLCHAIN_PREFIX = "xtensa-esp32-elf-"
DEFAULT_PRINT_FILTER = ""
class StoppableThread(object):
"""
Provide a Thread-like class which can be 'cancelled' via a subclass-provided
@ -165,7 +168,7 @@ class ConsoleReader(StoppableThread):
# this is the way cancel() is implemented in pyserial 3.3 or newer,
# older pyserial (3.1+) has cancellation implemented via 'select',
# which does not work when console sends an escape sequence response
#
#
# even older pyserial (<3.1) does not have this method
#
# on Windows there is a different (also hacky) fix, applied above.
@ -210,6 +213,57 @@ class SerialReader(StoppableThread):
except:
pass
class LineMatcher:
"""
Assembles a dictionary of filtering rules based on the --print_filter
argument of idf_monitor. Then later it is used to match lines and
determine whether they should be shown on screen or not.
"""
LEVEL_N = 0
LEVEL_E = 1
LEVEL_W = 2
LEVEL_I = 3
LEVEL_D = 4
LEVEL_V = 5
level = {'N': LEVEL_N, 'E': LEVEL_E, 'W': LEVEL_W, 'I': LEVEL_I, 'D': LEVEL_D,
'V': LEVEL_V, '*': LEVEL_V, '': LEVEL_V}
def __init__(self, print_filter):
self._dict = dict()
self._re = re.compile(r'^(?:\033\[[01];?[0-9]+m?)?([EWIDV]) \([0-9]+\) ([^:]+): ')
items = print_filter.split()
if len(items) == 0:
self._dict["*"] = self.LEVEL_V # default is to print everything
for f in items:
s = f.split(r':')
if len(s) == 1:
# specifying no warning level defaults to verbose level
lev = self.LEVEL_V
elif len(s) == 2:
if len(s[0]) == 0:
raise ValueError('No tag specified in filter ' + f)
try:
lev = self.level[s[1].upper()]
except KeyError:
raise ValueError('Unknown warning level in filter ' + f)
else:
raise ValueError('Missing ":" in filter ' + f)
self._dict[s[0]] = lev
def match(self, line):
try:
m = self._re.search(line)
if m:
lev = self.level[m.group(1)]
if m.group(2) in self._dict:
return self._dict[m.group(2)] >= lev
return self._dict.get("*", self.LEVEL_N) >= lev
except (KeyError, IndexError):
# Regular line written with something else than ESP_LOG*
# or an empty line.
pass
# We need something more than "*.N" for printing.
return self._dict.get("*", self.LEVEL_N) > self.LEVEL_N
class Monitor(object):
"""
@ -220,7 +274,7 @@ class Monitor(object):
Main difference is that all event processing happens in the main thread, not the worker threads.
"""
def __init__(self, serial_instance, elf_file, make="make", toolchain_prefix=DEFAULT_TOOLCHAIN_PREFIX, eol="CRLF"):
def __init__(self, serial_instance, elf_file, print_filter, make="make", toolchain_prefix=DEFAULT_TOOLCHAIN_PREFIX, eol="CRLF"):
super(Monitor, self).__init__()
self.event_queue = queue.Queue()
self.console = miniterm.Console()
@ -236,9 +290,9 @@ class Monitor(object):
if c == unichr(0x7f):
c = unichr(8) # map the BS key (which yields DEL) to backspace
return c
self.console.getkey = types.MethodType(getkey_patched, self.console)
self.console.getkey = types.MethodType(getkey_patched, self.console)
self.serial = serial_instance
self.console_reader = ConsoleReader(self.console, self.event_queue)
self.serial_reader = SerialReader(self.serial, self.event_queue)
@ -256,10 +310,17 @@ class Monitor(object):
# internal state
self._pressed_menu_key = False
self._read_line = b""
self._last_line_part = b""
self._gdb_buffer = b""
self._pc_address_buffer = b""
self._line_matcher = LineMatcher(print_filter)
self._invoke_processing_last_line_timer = None
self._force_line_print = False
self._output_enabled = True
def invoke_processing_last_line(self):
self.event_queue.put((TAG_SERIAL_FLUSH, b''), False)
def main_loop(self):
self.console_reader.start()
self.serial_reader.start()
@ -270,12 +331,26 @@ class Monitor(object):
self.handle_key(data)
elif event_tag == TAG_SERIAL:
self.handle_serial_input(data)
if self._invoke_processing_last_line_timer is not None:
self._invoke_processing_last_line_timer.cancel()
self._invoke_processing_last_line_timer = threading.Timer(1, self.invoke_processing_last_line)
self._invoke_processing_last_line_timer.start()
# If no futher data is received in the next short period
# of time then the _invoke_processing_last_line_timer
# generates an event which will result in the finishing of
# the last line. This is fix for handling lines sent
# without EOL.
elif event_tag == TAG_SERIAL_FLUSH:
self.handle_serial_input(data, finalize_line=True)
else:
raise RuntimeError("Bad event data %r" % ((event_tag,data),))
finally:
try:
self.console_reader.stop()
self.serial_reader.stop()
# Cancelling _invoke_processing_last_line_timer is not
# important here because receiving empty data doesn't matter.
self._invoke_processing_last_line_timer = None
except:
pass
sys.stderr.write(ANSI_NORMAL + "\n")
@ -298,20 +373,49 @@ class Monitor(object):
except UnicodeEncodeError:
pass # this can happen if a non-ascii character was passed, ignoring
def handle_serial_input(self, data):
# this may need to be made more efficient, as it pushes out a byte
# at a time to the console
for b in data:
if self._output_enabled:
self.console.write_bytes(b)
if b == b'\n': # end of line
self.handle_serial_input_line(self._read_line.strip())
self._read_line = b""
else:
self._read_line += b
self.check_gdbstub_trigger(b)
def handle_serial_input(self, data, finalize_line=False):
sp = data.split(b'\n')
if self._last_line_part != b"":
# add unprocessed part from previous "data" to the first line
sp[0] = self._last_line_part + sp[0]
self._last_line_part = b""
if sp[-1] != b"":
# last part is not a full line
self._last_line_part = sp.pop()
for line in sp:
if line != b"":
if self._output_enabled and (self._force_line_print or self._line_matcher.match(line)):
self.console.write_bytes(line + b'\n')
self.handle_possible_pc_address_in_line(line)
self.check_gdbstub_trigger(line)
self._force_line_print = False
# Now we have the last part (incomplete line) in _last_line_part. By
# default we don't touch it and just wait for the arrival of the rest
# of the line. But after some time when we didn't received it we need
# to make a decision.
if finalize_line and self._last_line_part != b"":
if self._line_matcher.match(self._last_line_part):
self._force_line_print = True;
if self._output_enabled:
self.console.write_bytes(self._last_line_part)
self.handle_possible_pc_address_in_line(self._last_line_part)
self.check_gdbstub_trigger(self._last_line_part)
# It is possible that the incomplete line cuts in half the PC
# address. A small buffer is kept and will be used the next time
# handle_possible_pc_address_in_line is invoked to avoid this problem.
# MATCH_PCADDR matches 10 character long addresses. Therefore, we
# keep the last 9 characters.
self._pc_address_buffer = self._last_line_part[-9:]
# GDB sequence can be cut in half also. GDB sequence is 7
# characters long, therefore, we save the last 6 characters.
self._gdb_buffer = self._last_line_part[-6:]
self._last_line_part = b""
# else: keeping _last_line_part and it will be processed the next time
# handle_serial_input is invoked
def handle_serial_input_line(self, line):
def handle_possible_pc_address_in_line(self, line):
line = self._pc_address_buffer + line
self._pc_address_buffer = b""
for m in re.finditer(MATCH_PCADDR, line):
self.lookup_pc_address(m.group())
@ -424,9 +528,10 @@ class Monitor(object):
if not "?? ??:0" in translation:
yellow_print(translation)
def check_gdbstub_trigger(self, c):
self._gdb_buffer = self._gdb_buffer[-6:] + c # keep the last 7 characters seen
m = re.match(b"\\$(T..)#(..)", self._gdb_buffer) # look for a gdb "reason" for a break
def check_gdbstub_trigger(self, line):
line = self._gdb_buffer + line
self._gdb_buffer = b""
m = re.search(b"\\$(T..)#(..)", line) # look for a gdb "reason" for a break
if m is not None:
try:
chsum = sum(ord(p) for p in m.group(1)) & 0xFF
@ -507,6 +612,11 @@ def main():
'elf_file', help='ELF file of application',
type=argparse.FileType('rb'))
parser.add_argument(
'--print_filter',
help="Filtering string",
default=DEFAULT_PRINT_FILTER)
args = parser.parse_args()
if args.port.startswith("/dev/tty."):
@ -532,7 +642,7 @@ def main():
except KeyError:
pass # not running a make jobserver
monitor = Monitor(serial_instance, args.elf_file.name, args.make, args.toolchain_prefix, args.eol)
monitor = Monitor(serial_instance, args.elf_file.name, args.print_filter, args.make, args.toolchain_prefix, args.eol)
yellow_print('--- idf_monitor on {p.name} {p.baudrate} ---'.format(
p=serial_instance))
@ -541,6 +651,8 @@ def main():
key_description(monitor.menu_key),
key_description(monitor.menu_key),
key_description(CTRL_H)))
if args.print_filter != DEFAULT_PRINT_FILTER:
yellow_print('--- Print filter: {} ---'.format(args.print_filter))
monitor.main_loop()