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
==============
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'
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
# 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.
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):
"""
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()
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)
# 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()
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")
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_line(self, line):
+ 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_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())
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
'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."):
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))
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()