Mirrors/esp-idf
1
0
Fork 0
mirror of https://github.com/espressif/esp-idf.git synced 2026-10-02 11:10:54 +03:00
Code Issues Packages Projects Releases Wiki Activity

Merge branch 'feat/enable_function_tracing_v6.0' into 'release/v6.0'

Browse Source 
Enable function tracing (-finstrument-functions) (v6.0)

See merge request espressif/esp-idf!52656
This commit is contained in:
Alexey Gerenkov
2026-09-22 22:17:19 +08:00
parent 1f98b3aca9 baa4ad4362
commit 9fa0e7a071
36 changed files with 1562 additions and 274 deletions
Download Patch File Download Diff File Expand all files Collapse all files
tools/esp_app_trace/espytrace/apptrace.py
+291 -240
View File
@@ -1,9 +1,7 @@
# SPDX-FileCopyrightText: 2022-2023 Espressif Systems (Shanghai) CO LTD
# SPDX-FileCopyrightText: 2022-2026 Espressif Systems (Shanghai) CO LTD
# SPDX-License-Identifier: Apache-2.0
from __future__ import print_function
import os
import sys
try:
from urlparse import urlparse
@@ -22,156 +20,190 @@ import elftools.elf.elffile as elffile
def clock():
if sys.version_info >= (3, 3):
return time.process_time()
else:
return time.clock()
return time.process_time()
def addr2line(toolchain, elf_path, addr):
"""
Creates trace reader.
Creates trace reader.
Parameters
----------
toolchain : string
toolchain prefix to retrieve source line locations using addresses
elf_path : string
path to ELF file to use
addr : int
address to retrieve source line location
Parameters
----------
toolchain : string
toolchain prefix to retrieve source line locations using addresses
elf_path : string
path to ELF file to use
addr : int
address to retrieve source line location
Returns
-------
string
source line location string
Returns
-------
string
source line location string
"""
try:
return subprocess.check_output(['%saddr2line' % toolchain, '-e', elf_path, '0x%x' % addr]).decode('utf-8')
return subprocess.check_output([f'{toolchain}addr2line', '-e', elf_path, f'0x{addr:x}']).decode('utf-8')
except subprocess.CalledProcessError:
return ''
def addr2symbol(toolchain, elf_path, addr):
"""
Resolves an address to its function name and source line location.
Parameters
----------
toolchain : string
toolchain prefix to retrieve symbol info using addresses
elf_path : string
path to ELF file to use
addr : int
address to resolve
Returns
-------
tuple
(function name, source line location) strings, empty on failure
"""
try:
out = (
subprocess.check_output([f'{toolchain}addr2line', '-f', '-e', elf_path, f'0x{addr:x}'])
.decode('utf-8')
.splitlines()
)
except subprocess.CalledProcessError:
return '', ''
func = out[0].strip() if len(out) > 0 else ''
line = out[1].strip() if len(out) > 1 else ''
return func, line
class ParseError(RuntimeError):
"""
Parse error exception
Parse error exception
"""
def __init__(self, message):
RuntimeError.__init__(self, message)
class ReaderError(RuntimeError):
"""
Trace reader error exception
Trace reader error exception
"""
def __init__(self, message):
RuntimeError.__init__(self, message)
class ReaderTimeoutError(ReaderError):
"""
Trace reader timeout error
Trace reader timeout error
"""
def __init__(self, tmo, sz):
ReaderError.__init__(self, 'Timeout %f sec while reading %d bytes!' % (tmo, sz))
ReaderError.__init__(self, f'Timeout {tmo:f} sec while reading {sz:d} bytes!')
class ReaderShutdownRequest(ReaderError):
"""
Trace reader shutdown request error
Raised when user presses CTRL+C (SIGINT).
Trace reader shutdown request error
Raised when user presses CTRL+C (SIGINT).
"""
def __init__(self):
ReaderError.__init__(self, 'Shutdown request!')
class Reader:
"""
Base abstract reader class
Base abstract reader class
"""
def __init__(self, tmo):
"""
Constructor
Constructor
Parameters
----------
tmo : int
read timeout
Parameters
----------
tmo : int
read timeout
"""
self.timeout = tmo
self.need_stop = False
def read(self, sz):
"""
Reads a number of bytes
Reads a number of bytes
Parameters
----------
sz : int
number of bytes to read
Parameters
----------
sz : int
number of bytes to read
Returns
-------
bytes object
read bytes
Returns
-------
bytes object
read bytes
Returns
-------
ReaderTimeoutError
if timeout expires
ReaderShutdownRequest
if SIGINT was received during reading
Returns
-------
ReaderTimeoutError
if timeout expires
ReaderShutdownRequest
if SIGINT was received during reading
"""
pass
def readline(self):
"""
Reads line
Reads line
Parameters
----------
sz : int
number of bytes to read
Parameters
----------
sz : int
number of bytes to read
Returns
-------
string
read line
Returns
-------
string
read line
"""
pass
def forward(self, sz):
"""
Moves read pointer to a number of bytes
Moves read pointer to a number of bytes
Parameters
----------
sz : int
number of bytes to read
Parameters
----------
sz : int
number of bytes to read
"""
pass
def cleanup(self):
"""
Cleans up reader
Cleans up reader
"""
self.need_stop = True
class FileReader(Reader):
"""
File reader class
File reader class
"""
def __init__(self, path, tmo):
"""
Constructor
Constructor
Parameters
----------
path : string
path to file to read
tmo : int
see Reader.__init__()
Parameters
----------
path : string
path to file to read
tmo : int
see Reader.__init__()
"""
Reader.__init__(self, tmo)
self.trace_file_path = path
@@ -179,7 +211,7 @@ class FileReader(Reader):
def read(self, sz):
"""
see Reader.read()
see Reader.read()
"""
data = b''
start_tm = clock()
@@ -195,18 +227,18 @@ class FileReader(Reader):
def get_pos(self):
"""
Retrieves current file read position
Retrieves current file read position
Returns
-------
int
read position
Returns
-------
int
read position
"""
return self.trace_file.tell()
def readline(self, linesep=os.linesep):
"""
see Reader.read()
see Reader.read()
"""
line = ''
start_tm = clock()
@@ -222,7 +254,7 @@ class FileReader(Reader):
def forward(self, sz):
"""
see Reader.read()
see Reader.read()
"""
cur_pos = self.trace_file.tell()
start_tm = clock()
@@ -239,8 +271,9 @@ class FileReader(Reader):
class NetRequestHandler:
"""
Handler for incoming network requests (connections, datagrams)
Handler for incoming network requests (connections, datagrams)
"""
def handle(self):
while not self.server.need_stop:
data = self.rfile.read(1024)
@@ -252,13 +285,14 @@ class NetRequestHandler:
class NetReader(FileReader):
"""
Base netwoek socket reader class
Base netwoek socket reader class
"""
def __init__(self, tmo):
"""
see Reader.__init__()
see Reader.__init__()
"""
fhnd,fname = tempfile.mkstemp()
fhnd, fname = tempfile.mkstemp()
FileReader.__init__(self, fname, tmo)
self.wtrace = os.fdopen(fhnd, 'wb')
self.server_thread = threading.Thread(target=self.serve_forever)
@@ -266,7 +300,7 @@ class NetReader(FileReader):
def cleanup(self):
"""
see Reader.cleanup()
see Reader.cleanup()
"""
FileReader.cleanup(self)
self.shutdown()
@@ -279,27 +313,29 @@ class NetReader(FileReader):
class TCPRequestHandler(NetRequestHandler, SocketServer.StreamRequestHandler):
"""
Handler for incoming TCP connections
Handler for incoming TCP connections
"""
pass
class TCPReader(NetReader, SocketServer.TCPServer):
"""
TCP socket reader class
TCP socket reader class
"""
def __init__(self, host, port, tmo, handler=TCPRequestHandler):
"""
Constructor
Constructor
Parameters
----------
host : string
see SocketServer.BaseServer.__init__()
port : int
see SocketServer.BaseServer.__init__()
tmo : int
see Reader.__init__()
Parameters
----------
host : string
see SocketServer.BaseServer.__init__()
port : int
see SocketServer.BaseServer.__init__()
tmo : int
see Reader.__init__()
"""
SocketServer.TCPServer.__init__(self, (host, port), handler)
NetReader.__init__(self, tmo)
@@ -307,27 +343,29 @@ class TCPReader(NetReader, SocketServer.TCPServer):
class UDPRequestHandler(NetRequestHandler, SocketServer.DatagramRequestHandler):
"""
Handler for incoming UDP datagrams
Handler for incoming UDP datagrams
"""
pass
class UDPReader(NetReader, SocketServer.UDPServer):
"""
UDP socket reader class
UDP socket reader class
"""
def __init__(self, host, port, tmo, handler=UDPRequestHandler):
"""
Constructor
Constructor
Parameters
----------
host : string
see SocketServer.BaseServer.__init__()
port : int
see SocketServer.BaseServer.__init__()
tmo : int
see Reader.__init__()
Parameters
----------
host : string
see SocketServer.BaseServer.__init__()
port : int
see SocketServer.BaseServer.__init__()
tmo : int
see Reader.__init__()
"""
SocketServer.UDPServer.__init__(self, (host, port), handler)
NetReader.__init__(self, tmo)
@@ -335,19 +373,19 @@ class UDPReader(NetReader, SocketServer.UDPServer):
def reader_create(trc_src, tmo, handler=None):
"""
Creates trace reader.
Creates trace reader.
Parameters
----------
trc_src : string
trace source URL. Supports 'file:///path/to/file' or (tcp|udp)://host:port
tmo : int
read timeout
Parameters
----------
trc_src : string
trace source URL. Supports 'file:///path/to/file' or (tcp|udp)://host:port
tmo : int
read timeout
Returns
-------
Reader
reader object or None if URL scheme is not supported
Returns
-------
Reader
reader object or None if URL scheme is not supported
"""
url = urlparse(trc_src)
if len(url.scheme) == 0 or url.scheme == 'file':
@@ -369,8 +407,9 @@ def reader_create(trc_src, tmo, handler=None):
class TraceEvent:
"""
Base class for all trace events.
Base class for all trace events.
"""
def __init__(self, name, core_id, evt_id):
self.name = name
self.ctx_name = 'None'
@@ -383,8 +422,8 @@ class TraceEvent:
@property
def ctx_desc(self):
if self.in_irq:
return 'IRQ "%s"' % self.ctx_name
return 'task "%s"' % self.ctx_name
return f'IRQ "{self.ctx_name}"'
return f'task "{self.ctx_name}"'
def to_jsonable(self):
res = self.__dict__
@@ -397,54 +436,55 @@ class TraceEvent:
class TraceDataProcessor:
"""
Base abstract class for all trace data processors.
Base abstract class for all trace data processors.
"""
def __init__(self, print_events, keep_all_events=False):
"""
Constructor.
Constructor.
Parameters
----------
print_events : bool
if True every event will be printed as they arrive
keep_all_events : bool
if True all events will be kept in self.events in the order they arrive
Parameters
----------
print_events : bool
if True every event will be printed as they arrive
keep_all_events : bool
if True all events will be kept in self.events in the order they arrive
"""
self.print_events = print_events
self.keep_all_events = keep_all_events
self.total_events = 0
self.events = []
# This can be changed by the root procesor that includes several sub-processors.
# This can be changed by the root processor that includes several sub-processors.
# It is used access some method of root processor which can contain methods/data common for all sub-processors.
# Common info could be current execution context, info about running tasks, available IRQs etc.
self.root_proc = self
def _print_event(self, event):
"""
Base method to print an event.
Base method to print an event.
Parameters
----------
event : object
Event object
Parameters
----------
event : object
Event object
"""
print('EVENT[{:d}]: {}'.format(self.total_events, event))
print(f'EVENT[{self.total_events:d}]: {event}')
def print_report(self):
"""
Base method to print report.
Base method to print report.
"""
print('Processed {:d} events'.format(self.total_events))
print(f'Processed {self.total_events:d} events')
def cleanup(self):
"""
Base method to make cleanups.
Base method to make cleanups.
"""
pass
def on_new_event(self, event):
"""
Base method to process event.
Base method to process event.
"""
if self.print_events:
self._print_event(event)
@@ -455,26 +495,27 @@ class TraceDataProcessor:
class LogTraceParseError(ParseError):
"""
Log trace parse error exception.
Log trace parse error exception.
"""
pass
def get_str_from_elf(felf, str_addr):
"""
Retrieves string from ELF file.
Retrieves string from ELF file.
Parameters
----------
felf : elffile.ELFFile
open ELF file handle to retrive format string from
str_addr : int
address of the string
Parameters
----------
felf : elffile.ELFFile
open ELF file handle to retrieve format string from
str_addr : int
address of the string
Returns
-------
string
string or None if it was not found
Returns
-------
string
string or None if it was not found
"""
tgt_str = ''
for sect in felf.iter_sections():
@@ -498,44 +539,45 @@ def get_str_from_elf(felf, str_addr):
class LogTraceEvent:
"""
Log trace event.
Log trace event.
"""
def __init__(self, fmt_addr, log_args):
"""
Constructor.
Constructor.
Parameters
----------
fmt_addr : int
address of the format string
log_args : list
list of log message arguments
Parameters
----------
fmt_addr : int
address of the format string
log_args : list
list of log message arguments
"""
self.fmt_addr = fmt_addr
self.args = log_args
def get_message(self, felf):
"""
Retrieves log message.
Retrieves log message.
Parameters
----------
felf : elffile.ELFFile
open ELF file handle to retrive format string from
Parameters
----------
felf : elffile.ELFFile
open ELF file handle to retrieve format string from
Returns
-------
string
formatted log message
Returns
-------
string
formatted log message
Raises
------
LogTraceParseError
if format string has not been found in ELF file
Raises
------
LogTraceParseError
if format string has not been found in ELF file
"""
fmt_str = get_str_from_elf(felf, self.fmt_addr)
if not fmt_str:
raise LogTraceParseError('Failed to find format string for 0x%x' % self.fmt_addr)
raise LogTraceParseError(f'Failed to find format string for 0x{self.fmt_addr:x}')
prcnt_idx = 0
for i, arg in enumerate(self.args):
prcnt_idx = fmt_str.find('%', prcnt_idx, -2) # TODO: check str ending with %
@@ -555,18 +597,19 @@ class LogTraceEvent:
class BaseLogTraceDataProcessorImpl:
"""
Base implementation for log data processors.
Base implementation for log data processors.
"""
def __init__(self, print_log_events=False, elf_path=''):
"""
Constructor.
Constructor.
Parameters
----------
print_log_events : bool
if True every log event will be printed as they arrive
elf_path : string
path to ELF file to retrieve format strings for log messages
Parameters
----------
print_log_events : bool
if True every log event will be printed as they arrive
elf_path : string
path to ELF file to retrieve format strings for log messages
"""
if len(elf_path):
self.felf = elffile.ELFFile(open(elf_path, 'rb'))
@@ -577,26 +620,26 @@ class BaseLogTraceDataProcessorImpl:
def cleanup(self):
"""
Cleanup
Cleanup
"""
if self.felf:
self.felf.stream.close()
def print_report(self):
"""
Prints log report
Prints log report
"""
print('=============== LOG TRACE REPORT ===============')
print('Processed {:d} log messages.'.format(len(self.messages)))
print(f'Processed {len(self.messages):d} log messages.')
def on_new_event(self, event):
"""
Processes log events.
Processes log events.
Parameters
----------
event : LogTraceEvent
Event object.
Parameters
----------
event : LogTraceEvent
Event object.
"""
msg = event.get_message(self.felf)
self.messages.append(msg)
@@ -606,51 +649,57 @@ class BaseLogTraceDataProcessorImpl:
class HeapTraceParseError(ParseError):
"""
Heap trace parse error exception.
Heap trace parse error exception.
"""
pass
class HeapTraceDuplicateAllocError(HeapTraceParseError):
"""
Heap trace duplicate allocation error exception.
Heap trace duplicate allocation error exception.
"""
def __init__(self, addr, new_size, prev_size):
"""
Constructor.
Constructor.
Parameters
----------
addr : int
memory block address
new_size : int
size of the new allocation
prev_size : int
size of the previous allocation
Parameters
----------
addr : int
memory block address
new_size : int
size of the new allocation
prev_size : int
size of the previous allocation
"""
HeapTraceParseError.__init__(self, """Duplicate alloc @ 0x{:x}!
New alloc is {:d} bytes,
previous is {:d} bytes.""".format(addr, new_size, prev_size))
HeapTraceParseError.__init__(
self,
f"""Duplicate alloc @ 0x{addr:x}!
New alloc is {new_size:d} bytes,
previous is {prev_size:d} bytes.""",
)
class HeapTraceEvent:
"""
Heap trace event.
Heap trace event.
"""
def __init__(self, trace_event, alloc, toolchain='', elf_path=''):
"""
Constructor.
Constructor.
Parameters
----------
sys_view_event : TraceEvent
trace event object related to this heap event
alloc : bool
True for allocation event, otherwise False
toolchain_pref : string
toolchain prefix to retrieve source line locations using addresses
elf_path : string
path to ELF file to retrieve format strings for log messages
Parameters
----------
sys_view_event : TraceEvent
trace event object related to this heap event
alloc : bool
True for allocation event, otherwise False
toolchain_pref : string
toolchain prefix to retrieve source line locations using addresses
elf_path : string
path to ELF file to retrieve format strings for log messages
"""
self.trace_event = trace_event
self.alloc = alloc
@@ -675,7 +724,7 @@ class HeapTraceEvent:
for addr in self.trace_event.params['callers'].value:
if addr == 0:
break
callers += '{}'.format(addr2line(self.toolchain, self.elf_path, addr))
callers += f'{addr2line(self.toolchain, self.elf_path, addr)}'
else:
callers = ''
for addr in self.trace_event.params['callers'].value:
@@ -683,31 +732,32 @@ class HeapTraceEvent:
break
if len(callers):
callers += ':'
callers += '0x{:x}'.format(addr)
callers += f'0x{addr:x}'
if self.alloc:
return '[{:.9f}] HEAP: Allocated {:d} bytes @ 0x{:x} from {} on core {:d} by: {}'.format(self.trace_event.ts,
self.size, self.addr,
self.trace_event.ctx_desc,
self.trace_event.core_id,
callers)
return (
f'[{self.trace_event.ts:.9f}] HEAP: Allocated {self.size:d} bytes @ 0x{self.addr:x} '
f'from {self.trace_event.ctx_desc} on core {self.trace_event.core_id:d} by: {callers}'
)
else:
return '[{:.9f}] HEAP: Freed bytes @ 0x{:x} from {} on core {:d} by: {}'.format(self.trace_event.ts,
self.addr, self.trace_event.ctx_desc,
self.trace_event.core_id, callers)
return (
f'[{self.trace_event.ts:.9f}] HEAP: Freed bytes @ 0x{self.addr:x} '
f'from {self.trace_event.ctx_desc} on core {self.trace_event.core_id:d} by: {callers}'
)
class BaseHeapTraceDataProcessorImpl:
"""
Base implementation for heap data processors.
Base implementation for heap data processors.
"""
def __init__(self, print_heap_events=False):
"""
Constructor.
Constructor.
Parameters
----------
print_heap_events : bool
if True every heap event will be printed as they arrive
Parameters
----------
print_heap_events : bool
if True every heap event will be printed as they arrive
"""
self._alloc_addrs = {}
self.allocs = []
@@ -717,12 +767,12 @@ class BaseHeapTraceDataProcessorImpl:
def on_new_event(self, event):
"""
Processes heap events. Keeps track of active allocations list.
Processes heap events. Keeps track of active allocations list.
Parameters
----------
event : HeapTraceEvent
Event object.
Parameters
----------
event : HeapTraceEvent
Event object.
"""
self.heap_events_count += 1
if self.print_heap_events:
@@ -733,7 +783,8 @@ class BaseHeapTraceDataProcessorImpl:
self.allocs.append(event)
self._alloc_addrs[event.addr] = event
else:
# do not treat free on unknown addresses as errors, because these blocks coould be allocated when tracing was disabled
# do not treat free on unknown addresses as errors, because these blocks
# coould be allocated when tracing was disabled
if event.addr in self._alloc_addrs:
event.size = self._alloc_addrs[event.addr].size
self.allocs.remove(self._alloc_addrs[event.addr])
@@ -743,10 +794,10 @@ class BaseHeapTraceDataProcessorImpl:
def print_report(self):
"""
Prints heap report
Prints heap report
"""
print('=============== HEAP TRACE REPORT ===============')
print('Processed {:d} heap events.'.format(self.heap_events_count))
print(f'Processed {self.heap_events_count:d} heap events.')
if len(self.allocs) == 0:
print('OK - Heap errors was not found.')
return
@@ -758,4 +809,4 @@ class BaseHeapTraceDataProcessorImpl:
if free.addr > alloc.addr and free.addr <= alloc.addr + alloc.size:
print('Possible wrong free operation found')
print(free)
print('Found {:d} leaked bytes in {:d} blocks.'.format(leaked_bytes, len(self.allocs)))
print(f'Found {leaked_bytes:d} leaked bytes in {len(self.allocs):d} blocks.')
tools/esp_app_trace/espytrace/sysview.py
+216 -25
View File
@@ -1,4 +1,4 @@
# SPDX-FileCopyrightText: 2022-2025 Espressif Systems (Shanghai) CO LTD
# SPDX-FileCopyrightText: 2022-2026 Espressif Systems (Shanghai) CO LTD
# SPDX-License-Identifier: Apache-2.0
import copy
import json
@@ -175,7 +175,7 @@ def _read_init_seq(reader):
SysViewTraceParseError
If sync sequence is broken.
"""
SYNC_SEQ_FMT = '<%dB' % SYSVIEW_SYNC_LEN
SYNC_SEQ_FMT = f'<{SYSVIEW_SYNC_LEN}B'
sync_bytes = struct.unpack(SYNC_SEQ_FMT, reader.read(struct.calcsize(SYNC_SEQ_FMT)))
for b in sync_bytes:
if b != 0:
@@ -266,7 +266,7 @@ def _decode_str(reader):
if sz == 0xFF:
buf = struct.unpack('<2B', reader.read(2))
sz = (buf[0] << 8) | buf[1]
(val,) = struct.unpack('<%ds' % sz, reader.read(sz))
(val,) = struct.unpack(f'<{sz}s', reader.read(sz))
val = val.decode('utf-8')
if sz < 0xFF:
return (sz + 1, val) # one extra byte for length
@@ -353,7 +353,7 @@ class SysViewEvent(apptrace.TraceEvent):
if event has unknown or invalid format.
"""
if self.id not in events_fmt_map:
raise SysViewTraceParseError('Unknown event ID %d!' % self.id)
raise SysViewTraceParseError(f'Unknown event ID {self.id}!')
self.name = events_fmt_map[self.id][0]
evt_params_templates = events_fmt_map[self.id][1]
params_len = 0
@@ -364,9 +364,7 @@ class SysViewEvent(apptrace.TraceEvent):
sz, param_val = event_param.decode(reader, self.plen - params_len)
except Exception as e:
raise SysViewTraceParseError(
'Failed to decode event {}({:d}) {:d} param @ 0x{:x}! {}'.format(
self.name, self.id, self.plen, cur_pos, e
)
f'Failed to decode event {self.name}({self.id:d}) {self.plen:d} param @ 0x{cur_pos:x}! {e}'
)
event_param.idx = i
event_param.value = param_val
@@ -374,20 +372,16 @@ class SysViewEvent(apptrace.TraceEvent):
params_len += sz
if self.id >= SYSVIEW_EVENT_ID_PREDEF_LEN_MAX and self.plen != params_len:
raise SysViewTraceParseError(
'Invalid event {}({:d}) payload len {:d}! Must be {:d}.'.format(
self.name, self.id, self.plen, params_len
)
f'Invalid event {self.name}({self.id:d}) payload len {self.plen:d}! Must be {params_len:d}.'
)
def __str__(self):
params = ''
for param in sorted(self.params.values(), key=lambda x: x.idx):
params += '{}, '.format(param)
params += f'{param}, '
if len(params):
params = params[:-2] # remove trailing ', '
return '{:.9f} - core[{:d}].{}({:d}), plen {:d}: [{}]'.format(
self.ts, self.core_id, self.name, self.id, self.plen, params
)
return f'{self.ts:.9f} - core[{self.core_id:d}].{self.name}({self.id:d}), plen {self.plen:d}: [{params}]'
class SysViewEventParam:
@@ -431,7 +425,7 @@ class SysViewEventParam:
pass
def __str__(self):
return '{}: {}'.format(self.name, self.value)
return f'{self.name}: {self.value}'
def to_jsonable(self):
return {self.name: self.value}
@@ -634,6 +628,49 @@ class SysViewHeapEvent(SysViewEvent):
# self.name = 'SysViewHeapEvent'
class SysViewFunctionEvent(SysViewEvent):
"""
Function tracing related SystemView events class.
Attributes
----------
events_fmt : dict
see return value of _read_events_map()
"""
events_fmt = {
0: (
'esp_sysview_function_enter',
[SysViewEventParamSimple('func', _decode_u32), SysViewEventParamSimple('call_site', _decode_u32)],
),
1: (
'esp_sysview_function_exit',
[SysViewEventParamSimple('func', _decode_u32), SysViewEventParamSimple('call_site', _decode_u32)],
),
}
def __init__(self, evt_id, core_id, events_off, reader):
"""
Constructor. Reads and optionally decodes event.
Parameters
----------
evt_id : int
see SysViewEvent.__init__()
events_off : int
Offset for function events IDs. Greater or equal to SYSVIEW_MODULE_EVENT_OFFSET.
reader : apptrace.Reader
see SysViewEvent.__init__()
core_id : int
see SysViewEvent.__init__()
"""
cur_events_map = {}
for _id in self.events_fmt:
cur_events_map[events_off + _id] = self.events_fmt[_id]
SysViewEvent.__init__(self, evt_id, core_id, reader, cur_events_map)
# self.name = 'SysViewFunctionEvent'
class SysViewTraceDataParser(apptrace.TraceDataProcessor):
"""
Base SystemView trace data parser class.
@@ -646,11 +683,14 @@ class SysViewTraceDataParser(apptrace.TraceDataProcessor):
log events stream ID.
STREAMID_HEAP : int
heap events stream ID.
STREAMID_FUNC : int
function tracing events stream ID.
"""
STREAMID_SYS = -1
STREAMID_LOG = 0
STREAMID_HEAP = 1
STREAMID_FUNC = 2
def __init__(self, print_events=False, core_id=0):
"""
@@ -984,7 +1024,7 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor):
if len(self.root_proc.ctx_stack[core_id]):
return self.root_proc.ctx_stack[core_id][-1]
if self._get_prev_context(core_id):
return SysViewEventContext(None, False, 'IDLE%d' % core_id)
return SysViewEventContext(None, False, f'IDLE{core_id}')
return None
def _get_prev_context(self, core_id):
@@ -1059,18 +1099,18 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor):
if SYSVIEW_EVTID_TASK_START_EXEC or SYSVIEW_EVTID_TASK_STOP_READY is received for unknown task.
"""
if event.core_id not in self.traces:
raise SysViewTraceParseError('Event for unknown core %d' % event.core_id)
raise SysViewTraceParseError(f'Event for unknown core {event.core_id}')
else:
trace = self.traces[event.core_id]
if event.id == SYSVIEW_EVTID_ISR_ENTER:
if event.params['irq_num'].value not in trace.irqs_info:
raise SysViewTraceParseError('Enter unknown ISR %d' % event.params['irq_num'].value)
raise SysViewTraceParseError(f'Enter unknown ISR {event.params["irq_num"].value}')
if len(self.ctx_stack[event.core_id]):
self.prev_ctx[event.core_id] = self.ctx_stack[event.core_id][-1]
else:
# the 1st context switching event after trace start is SYSVIEW_EVTID_ISR_ENTER,
# so we have been in IDLE context
self.prev_ctx[event.core_id] = SysViewEventContext(None, False, 'IDLE%d' % event.core_id)
self.prev_ctx[event.core_id] = SysViewEventContext(None, False, f'IDLE{event.core_id}')
# put new ISR context on top of the stack (the last in the list)
self.ctx_stack[event.core_id].append(
SysViewEventContext(event.params['irq_num'].value, True, trace.irqs_info[event.params['irq_num'].value])
@@ -1083,17 +1123,17 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor):
# the 1st context switching event after trace start is SYSVIEW_EVTID_ISR_EXIT,
# so we have been in ISR context,
# but we do not know which one because SYSVIEW_EVTID_ISR_EXIT do not include the IRQ number
self.prev_ctx[event.core_id] = SysViewEventContext(None, True, 'IRQ_oncore%d' % event.core_id)
self.prev_ctx[event.core_id] = SysViewEventContext(None, True, f'IRQ_oncore{event.core_id}')
elif event.id == SYSVIEW_EVTID_TASK_START_EXEC:
if event.params['tid'].value not in trace.tasks_info:
raise SysViewTraceParseError('Start exec unknown task 0x%x' % event.params['tid'].value)
raise SysViewTraceParseError(f'Start exec unknown task 0x{event.params["tid"].value:x}')
if len(self.ctx_stack[event.core_id]):
# return to the previous context (the last in the list)
self.prev_ctx[event.core_id] = self.ctx_stack[event.core_id][-1]
else:
# the 1st context switching event after trace start is SYSVIEW_EVTID_TASK_START_EXEC,
# so we have been in IDLE context
self.prev_ctx[event.core_id] = SysViewEventContext(None, False, 'IDLE%d' % event.core_id)
self.prev_ctx[event.core_id] = SysViewEventContext(None, False, f'IDLE{event.core_id}')
# only one task at a time in context stack (can be interrupted by a bunch of ISRs)
self.ctx_stack[event.core_id] = [
SysViewEventContext(event.params['tid'].value, False, trace.tasks_info[event.params['tid'].value])
@@ -1109,7 +1149,7 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor):
break
elif event.id == SYSVIEW_EVTID_TASK_STOP_READY:
if event.params['tid'].value not in trace.tasks_info:
raise SysViewTraceParseError('Stop ready unknown task 0x%x' % event.params['tid'].value)
raise SysViewTraceParseError(f'Stop ready unknown task 0x{event.params["tid"].value:x}')
if len(self.ctx_stack[event.core_id]):
if (
not self.ctx_stack[event.core_id][-1].irq
@@ -1282,7 +1322,7 @@ class SysViewTraceDataJsonEncoder(json.JSONEncoder):
blk_addr = '0x{:x}'.format(obj.params['addr'].value)
callers = []
for addr in obj.params['callers'].value:
callers.append('0x{:x}'.format(addr))
callers.append(f'0x{addr:x}')
return {
'ctx_name': obj.ctx_name,
'in_irq': obj.in_irq,
@@ -1355,6 +1395,43 @@ class SysViewHeapTraceDataParser(SysViewTraceDataExtEventParser):
self.events_off = event.params['evt_off'].value
class SysViewFunctionTraceDataParser(SysViewTraceDataExtEventParser):
"""
SystemView trace data parser supporting function tracing events.
"""
def __init__(self, print_events=False, core_id=0):
"""
SystemView trace data parser supporting multiple event streams.
see SysViewTraceDataExtEventParser.__init__()
"""
SysViewTraceDataExtEventParser.__init__(
self, events_num=len(SysViewFunctionEvent.events_fmt.keys()), core_id=core_id, print_events=print_events
)
def read_extension_event(self, evt_id, core_id, reader):
"""
Reads function tracing event.
see SysViewTraceDataParser.read_extension_event()
"""
if (
self.events_off >= SYSVIEW_MODULE_EVENT_OFFSET
and evt_id >= self.events_off
and evt_id < self.events_off + self.events_num
):
return SysViewFunctionEvent(evt_id, core_id, self.events_off, reader)
return SysViewTraceDataParser.read_extension_event(self, evt_id, core_id, reader)
def on_new_event(self, event):
"""
Keeps track of function tracing module descriptions, when present.
"""
if self.root_proc == self:
SysViewTraceDataParser.on_new_event(self, event)
if event.id == SYSVIEW_EVTID_MODULEDESC and event.params['desc'].value.startswith('M=ESP_FunctionTrace'):
self.events_off = event.params['evt_off'].value
class SysViewHeapTraceDataProcessor(SysViewTraceDataProcessor, apptrace.BaseHeapTraceDataProcessorImpl):
"""
SystemView trace data processor supporting heap events.
@@ -1398,6 +1475,120 @@ class SysViewHeapTraceDataProcessor(SysViewTraceDataProcessor, apptrace.BaseHeap
apptrace.BaseHeapTraceDataProcessorImpl.print_report(self)
class SysViewFunctionTraceEvent:
"""
Function tracing event (enter or exit).
"""
def __init__(self, trace_event, enter, toolchain='', elf_path=''):
"""
Constructor.
Parameters
----------
trace_event : SysViewEvent
trace event object related to this function event
enter : bool
True for function enter event, otherwise False
toolchain : string
toolchain prefix to resolve addresses to source line locations
elf_path : string
path to ELF file to resolve addresses
"""
self.trace_event = trace_event
self.enter = enter
self.toolchain = toolchain
self.elf_path = elf_path
@property
def func(self):
return self.trace_event.params['func'].value
@property
def call_site(self):
return self.trace_event.params['call_site'].value
def __repr__(self):
if len(self.toolchain) and len(self.elf_path):
name, location = apptrace.addr2symbol(self.toolchain, self.elf_path, self.func)
func = f'{name} ({location})' if name else f'0x{self.func:x}'
call_site = apptrace.addr2line(self.toolchain, self.elf_path, self.call_site).strip()
else:
func = f'0x{self.func:x}'
call_site = f'0x{self.call_site:x}'
return '[{:.9f}] FUNC: {} {} from {} on core {:d} (called at {})'.format(
self.trace_event.ts,
'enter' if self.enter else 'exit',
func,
self.trace_event.ctx_desc,
self.trace_event.core_id,
call_site,
)
class SysViewFunctionTraceDataProcessor(SysViewTraceDataProcessor):
"""
SystemView trace data processor supporting function tracing events.
"""
def __init__(
self, toolchain_pref, elf_path, root_proc=None, traces=[], print_events=False, print_func_events=False
):
"""
Constructor.
see SysViewTraceDataProcessor.__init__()
"""
SysViewTraceDataProcessor.__init__(self, traces, root_proc=root_proc, print_events=print_events)
self.toolchain = toolchain_pref
self.elf_path = elf_path
self.name = 'func'
self.print_func_events = print_func_events
self.func_events_count = 0
# per-function [enter, exit] counts keyed by function address
self.func_stats = {}
stream = self.root_proc.get_trace_stream(0, SysViewTraceDataParser.STREAMID_FUNC)
self.event_ids = {'enter': stream.events_off, 'exit': stream.events_off + 1}
def event_supported(self, event):
func_stream = self.root_proc.get_trace_stream(event.core_id, SysViewTraceDataParser.STREAMID_FUNC)
return func_stream.event_supported(event)
def handle_event(self, event):
func_stream = self.root_proc.get_trace_stream(event.core_id, SysViewTraceDataParser.STREAMID_FUNC)
enter = (event.id - func_stream.events_off) == 0
func_event = SysViewFunctionTraceEvent(event, enter, toolchain=self.toolchain, elf_path=self.elf_path)
self.func_events_count += 1
if self.print_func_events:
print(func_event)
stats = self.func_stats.setdefault(func_event.func, [0, 0])
stats[0 if enter else 1] += 1
def print_report(self):
"""
see apptrace.TraceDataProcessor.print_report()
"""
if self.root_proc == self:
SysViewTraceDataProcessor.print_report(self)
print('=============== FUNCTION TRACE REPORT ===============')
print(f'Processed {self.func_events_count:d} function trace events.')
# sort by enter count to show the most frequently called functions first
rows = []
for func in sorted(self.func_stats, key=lambda a: self.func_stats[a][0], reverse=True):
enter_cnt, exit_cnt = self.func_stats[func]
if len(self.toolchain) and len(self.elf_path):
name, location = apptrace.addr2symbol(self.toolchain, self.elf_path, func)
else:
name, location = '', ''
rows.append((name, func, enter_cnt, exit_cnt, location))
name_w = max((len(r[0]) for r in rows), default=0)
for name, func, enter_cnt, exit_cnt, location in rows:
print(
'{:<{nw}} 0x{:08x} enter={:<6d} exit={:<6d} {}'.format(
name, func, enter_cnt, exit_cnt, location, nw=name_w
)
)
class SysViewLogTraceEvent(apptrace.LogTraceEvent):
"""
SystemView log event.
@@ -1424,7 +1615,7 @@ class SysViewLogTraceEvent(apptrace.LogTraceEvent):
string
formatted log message
"""
return '[{:.9f}] LOG: {}'.format(self.ts, self.msg)
return f'[{self.ts:.9f}] LOG: {self.msg}'
class SysViewLogTraceDataParser(SysViewTraceDataParser):
tools/esp_app_trace/sysviewtrace_proc.py
+17 -3
View File
@@ -1,6 +1,6 @@
#!/usr/bin/env python
#
# SPDX-FileCopyrightText: 2019-2025 Espressif Systems (Shanghai) CO LTD
# SPDX-FileCopyrightText: 2019-2026 Espressif Systems (Shanghai) CO LTD
# SPDX-License-Identifier: Apache-2.0
#
# This is python script to process various types trace data streams in SystemView format.
@@ -125,7 +125,7 @@ def main():
'-i',
help='Events types to be included into report.',
type=str,
choices=['heap', 'log', 'all'],
choices=['heap', 'log', 'func', 'all'],
default='all',
)
parser.add_argument('--toolchain', '-t', help='Toolchain prefix.', type=str, default='xtensa-esp32-elf-')
@@ -152,7 +152,7 @@ def main():
signal.signal(signal.SIGINT, sig_int_handler)
include_events = {'heap': False, 'log': False}
include_events = {'heap': False, 'log': False, 'func': False}
if args.include_events == 'all':
for k in include_events:
include_events[k] = True
@@ -160,6 +160,8 @@ def main():
include_events['heap'] = True
elif args.include_events == 'log':
include_events['log'] = True
elif args.include_events == 'func':
include_events['func'] = True
logging.basicConfig(level=verbosity_levels[args.verbose], format='[%(levelname)s] %(message)s')
@@ -190,6 +192,11 @@ def main():
sysview.SysViewTraceDataParser.STREAMID_LOG,
sysview.SysViewLogTraceDataParser(print_events=False, core_id=i),
)
if include_events['func']:
parser.add_stream_parser(
sysview.SysViewTraceDataParser.STREAMID_FUNC,
sysview.SysViewFunctionTraceDataParser(print_events=False, core_id=i),
)
parsers.append(parser)
except Exception as e:
logging.error('Failed to create data parser (%s)!', e)
@@ -231,6 +238,13 @@ def main():
sysview.SysViewTraceDataParser.STREAMID_LOG,
sysview.SysViewLogTraceDataProcessor(root_proc=proc, print_log_events=args.print_events),
)
if include_events['func']:
proc.add_stream_processor(
sysview.SysViewTraceDataParser.STREAMID_FUNC,
sysview.SysViewFunctionTraceDataProcessor(
args.toolchain, args.elf_file, root_proc=proc, print_func_events=args.print_events
),
)
except Exception as e:
logging.error('Failed to create data processor (%s)!', e)
traceback.print_exc()
tools/esp_app_trace/test/sysview/expected_output
+2
View File
@@ -3737,3 +3737,5 @@ Processed 99 heap events.
/Users/erhan/dev/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:141
Found 17706 leaked bytes in 45 blocks.
=============== FUNCTION TRACE REPORT ===============
Processed 0 function trace events.
tools/esp_app_trace/test/sysview/expected_output.json
+4
View File
@@ -26180,6 +26180,10 @@
}
],
"streams": {
"func": {
"enter": 0,
"exit": 1
},
"heap": {
"alloc": 512,
"free": 513
tools/esp_app_trace/test/sysview/expected_output_mcore
+2
View File
@@ -3748,3 +3748,5 @@ Processed 99 heap events.
/Users/erhan/dev/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:141
Found 17706 leaked bytes in 45 blocks.
=============== FUNCTION TRACE REPORT ===============
Processed 0 function trace events.
tools/esp_app_trace/test/sysview/expected_output_mcore.json
+4
View File
@@ -26268,6 +26268,10 @@
}
],
"streams": {
"func": {
"enter": 0,
"exit": 1
},
"heap": {
"alloc": 512,
"free": 513