From 884717fb2f2a4284b4c712fcece5ee9d4250750f Mon Sep 17 00:00:00 2001 From: Alexey Gerenkov Date: Wed, 20 Nov 2019 14:47:07 +0300 Subject: [PATCH 1/2] apptrace: Adds support for converting SystemView traces to JSON format --- components/heap/include/heap_trace.inc | 1 + docs/en/api-reference/system/heap_debug.rst | 2 +- tools/ci/executable-list.txt | 1 + tools/esp_app_trace/espytrace/apptrace.py | 106 +- tools/esp_app_trace/espytrace/sysview.py | 261 +- tools/esp_app_trace/sysviewtrace_proc.py | 50 +- .../test/sysview/compare_json.py | 16 + .../test/sysview/expected_output | 6 - .../test/sysview/expected_output.json | 3960 +++++++++++++++++ tools/esp_app_trace/test/sysview/test.sh | 10 +- 10 files changed, 4288 insertions(+), 125 deletions(-) create mode 100755 tools/esp_app_trace/test/sysview/compare_json.py create mode 100644 tools/esp_app_trace/test/sysview/expected_output.json diff --git a/components/heap/include/heap_trace.inc b/components/heap/include/heap_trace.inc index a51b07a6a..7c3c4332e 100644 --- a/components/heap/include/heap_trace.inc +++ b/components/heap/include/heap_trace.inc @@ -35,6 +35,7 @@ inline static uint32_t get_ccount(void) } \ callers[N] = __builtin_return_address(N+STACK_OFFSET); \ if (!esp_ptr_executable(callers[N])) { \ + callers[N] = 0; \ return; \ } \ } while(0) diff --git a/docs/en/api-reference/system/heap_debug.rst b/docs/en/api-reference/system/heap_debug.rst index 02aaf3db2..fe0882e9d 100644 --- a/docs/en/api-reference/system/heap_debug.rst +++ b/docs/en/api-reference/system/heap_debug.rst @@ -284,7 +284,7 @@ Using this file GDB will connect to the target, reset it, and start tracing when 5. Quit GDB when program stops at :cpp:func:`heap_trace_stop`. Trace data are saved in ``/tmp/heap.svdat`` -6. Run processing script ``$IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py /tmp/heap_log.svdat `` +6. Run processing script ``$IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -p -b /tmp/heap_log.svdat`` The output from the heap trace will look something like this:: diff --git a/tools/ci/executable-list.txt b/tools/ci/executable-list.txt index 53795a489..9b39d0d9d 100644 --- a/tools/ci/executable-list.txt +++ b/tools/ci/executable-list.txt @@ -61,6 +61,7 @@ tools/elf_to_ld.sh tools/esp_app_trace/logtrace_proc.py tools/esp_app_trace/sysviewtrace_proc.py tools/esp_app_trace/test/logtrace/test.sh +tools/esp_app_trace/test/sysview/compare_json.py tools/esp_app_trace/test/sysview/test.sh tools/find_apps.py tools/format.sh diff --git a/tools/esp_app_trace/espytrace/apptrace.py b/tools/esp_app_trace/espytrace/apptrace.py index b793ce64f..cb0652438 100644 --- a/tools/esp_app_trace/espytrace/apptrace.py +++ b/tools/esp_app_trace/espytrace/apptrace.py @@ -1,3 +1,4 @@ +import sys import os try: from urlparse import urlparse @@ -16,6 +17,13 @@ import elftools.elf.elffile as elffile import elftools.elf.constants as elfconst +def clock(): + if sys.version_info >= (3, 3): + return time.process_time() + else: + return time.clock() + + def addr2line(toolchain, elf_path, addr): """ Creates trace reader. @@ -170,12 +178,12 @@ class FileReader(Reader): see Reader.read() """ data = b'' - start_tm = time.clock() + start_tm = clock() while not self.need_stop: data += self.trace_file.read(sz - len(data)) if len(data) == sz: break - if self.timeout != -1 and time.clock() >= start_tm + self.timeout: + if self.timeout != -1 and clock() >= start_tm + self.timeout: raise ReaderTimeoutError(self.timeout, sz) if self.need_stop: raise ReaderShutdownRequest() @@ -197,12 +205,12 @@ class FileReader(Reader): see Reader.read() """ line = '' - start_tm = time.clock() + start_tm = clock() while not self.need_stop: line += self.trace_file.readline().decode("utf-8") if line.endswith(linesep): break - if self.timeout != -1 and time.clock() >= start_tm + self.timeout: + if self.timeout != -1 and clock() >= start_tm + self.timeout: raise ReaderTimeoutError(self.timeout, 1) if self.need_stop: raise ReaderShutdownRequest() @@ -213,12 +221,12 @@ class FileReader(Reader): see Reader.read() """ cur_pos = self.trace_file.tell() - start_tm = time.clock() + start_tm = clock() while not self.need_stop: file_sz = os.path.getsize(self.trace_file_path) if file_sz - cur_pos >= sz: break - if self.timeout != -1 and time.clock() >= start_tm + self.timeout: + if self.timeout != -1 and clock() >= start_tm + self.timeout: raise ReaderTimeoutError(self.timeout, sz) if self.need_stop: raise ReaderShutdownRequest() @@ -351,6 +359,34 @@ def reader_create(trc_src, tmo): return None +class TraceEvent: + """ + Base class for all trace events. + """ + def __init__(self, name, core_id, evt_id): + self.name = name + self.ctx_name = 'None' + self.in_irq = False + self.core_id = core_id + self.id = evt_id + self.ts = 0 + self.params = {} + + @property + def ctx_desc(self): + if self.in_irq: + return 'IRQ "%s"' % self.ctx_name + return 'task "%s"' % self.ctx_name + + def to_jsonable(self): + res = self.__dict__ + params = {} + for p in self.params: + params.update(self.params[p].to_jsonable()) + res['params'] = params + return res + + class TraceDataProcessor: """ Base abstract class for all trace data processors. @@ -593,66 +629,58 @@ class HeapTraceEvent: """ Heap trace event. """ - def __init__(self, ctx_name, in_irq, core_id, ts, alloc, size, addr, callers, toolchain='', elf_path=''): + def __init__(self, trace_event, alloc, toolchain='', elf_path=''): """ Constructor. Parameters ---------- - ctx_name : string - name of event context (task or IRQ name) - in_irq : bool - True if event has been generated in IRQ context, otherwise False - core_id : int - core which generated the event - ts : float - event timestamp + sys_view_event : TraceEvent + trace event object related to this heap event alloc : bool True for allocation event, otherwise False - size : int - size of allocation; has no meaning for de-allocation event - addr : int - address of allocation/de-allocation - callers : list - list of callers (callstack) for event 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.ctx_name = ctx_name - self.in_irq = in_irq - self.core_id = core_id - self.ts = ts + self.trace_event = trace_event self.alloc = alloc - self.size = size - self.addr = addr - self.callers = callers self.toolchain = toolchain self.elf_path = elf_path + if self.alloc: + self.size = self.trace_event.params['size'].value + else: + self.size = None + + @property + def addr(self): + return self.trace_event.params['addr'].value def __repr__(self): if len(self.toolchain) and len(self.elf_path): callers = os.linesep - for addr in self.callers: + for addr in self.trace_event.params['callers'].value: + if addr == 0: + break callers += '{}'.format(addr2line(self.toolchain, self.elf_path, addr)) else: callers = '' - for addr in self.callers: + for addr in self.trace_event.params['callers'].value: + if addr == 0: + break if len(callers): callers += ':' callers += '0x{:x}'.format(addr) - if self.in_irq: - ctx_desc = 'IRQ "%s"' % self.ctx_name - else: - ctx_desc = 'task "%s"' % self.ctx_name if self.alloc: - return "[{:.9f}] HEAP: Allocated {:d} bytes @ 0x{:x} from {} on core {:d} by: {}".format(self.ts, self.size, - self.addr, ctx_desc, - self.core_id, callers) + 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) else: - return "[{:.9f}] HEAP: Freed bytes @ 0x{:x} from {} on core {:d} by: {}".format(self.ts, self.addr, ctx_desc, - self.core_id, callers) + 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) class BaseHeapTraceDataProcessorImpl: diff --git a/tools/esp_app_trace/espytrace/sysview.py b/tools/esp_app_trace/espytrace/sysview.py index 66ed0dde7..00ffba52f 100644 --- a/tools/esp_app_trace/espytrace/sysview.py +++ b/tools/esp_app_trace/espytrace/sysview.py @@ -1,6 +1,7 @@ import re import struct import copy +import json import espytrace.apptrace as apptrace @@ -40,6 +41,38 @@ SYSVIEW_MODULE_EVENT_OFFSET = 512 SYSVIEW_SYNC_LEN = 10 +_sysview_events_map = { + "SYS_NOP": SYSVIEW_EVTID_NOP, + "SYS_OVERFLOW": SYSVIEW_EVTID_OVERFLOW, + "SYS_ISR_ENTER": SYSVIEW_EVTID_ISR_ENTER, + "SYS_ISR_EXIT": SYSVIEW_EVTID_ISR_EXIT, + "SYS_TASK_START_EXEC": SYSVIEW_EVTID_TASK_START_EXEC, + "SYS_TASK_STOP_EXEC": SYSVIEW_EVTID_TASK_STOP_EXEC, + "SYS_TASK_START_READY": SYSVIEW_EVTID_TASK_START_READY, + "SYS_TASK_STOP_READY": SYSVIEW_EVTID_TASK_STOP_READY, + "SYS_TASK_CREATE": SYSVIEW_EVTID_TASK_CREATE, + "SYS_TASK_INFO": SYSVIEW_EVTID_TASK_INFO, + "SYS_TRACE_START": SYSVIEW_EVTID_TRACE_START, + "SYS_TRACE_STOP": SYSVIEW_EVTID_TRACE_STOP, + "SYS_SYSTIME_CYCLES": SYSVIEW_EVTID_SYSTIME_CYCLES, + "SYS_SYSTIME_US": SYSVIEW_EVTID_SYSTIME_US, + "SYS_SYSDESC": SYSVIEW_EVTID_SYSDESC, + "SYS_USER_START": SYSVIEW_EVTID_USER_START, + "SYS_USER_STOP": SYSVIEW_EVTID_USER_STOP, + "SYS_IDLE": SYSVIEW_EVTID_IDLE, + "SYS_ISR_TO_SCHEDULER": SYSVIEW_EVTID_ISR_TO_SCHEDULER, + "SYS_TIMER_ENTER": SYSVIEW_EVTID_TIMER_ENTER, + "SYS_TIMER_EXIT": SYSVIEW_EVTID_TIMER_EXIT, + "SYS_STACK_INFO": SYSVIEW_EVTID_STACK_INFO, + "SYS_MODULEDESC": SYSVIEW_EVTID_INIT, + "SYS_INIT": SYSVIEW_EVTID_INIT, + "SYS_NAME_RESOURCE": SYSVIEW_EVTID_NAME_RESOURCE, + "SYS_PRINT_FORMATTED": SYSVIEW_EVTID_PRINT_FORMATTED, + "SYS_NUMMODULES": SYSVIEW_EVTID_NUMMODULES +} + +_os_events_map = {} + def parse_trace(reader, parser, os_evt_map_file=''): """ @@ -54,12 +87,13 @@ def parse_trace(reader, parser, os_evt_map_file=''): os_evt_map_file : string Path to file containg events format description. """ + global _os_events_map # parse OS events formats file - os_evt_map = _read_events_map(os_evt_map_file) + _os_events_map = _read_events_map(os_evt_map_file) _read_file_header(reader) _read_init_seq(reader) while True: - event = parser.read_event(reader, os_evt_map) + event = parser.read_event(reader, _os_events_map) parser.on_new_event(event) @@ -267,7 +301,7 @@ class SysViewTraceParseError(apptrace.ParseError): pass -class SysViewEvent: +class SysViewEvent(apptrace.TraceEvent): """ Generic SystemView event class. This is a base class for all events. """ @@ -286,11 +320,8 @@ class SysViewEvent: events_fmt_map : dict see return value of _read_events_map() """ - self.name = 'SysViewEvent' - self.core_id = core_id - self.id = evt_id + apptrace.TraceEvent.__init__(self, 'SysViewEvent', core_id, evt_id) self.plen = 0 - self.params = {} if self.id >= SYSVIEW_EVENT_ID_PREDEF_LEN_MAX: self.plen = _decode_plen(reader) if events_fmt_map: @@ -385,6 +416,9 @@ class SysViewEventParam: def __str__(self): return '{}: {}'.format(self.name, self.value) + def to_jsonable(self): + return {self.name: self.value} + class SysViewEventParamSimple(SysViewEventParam): """ @@ -477,7 +511,7 @@ class SysViewPredefinedEvent(SysViewEvent): SYSVIEW_EVTID_NAME_RESOURCE: ('svNameResource', [SysViewEventParamSimple('res_id', _decode_u32), SysViewEventParamSimple('name', _decode_str)]), SYSVIEW_EVTID_PRINT_FORMATTED: ('svPrint', [SysViewEventParamSimple('msg', _decode_str), - SysViewEventParamSimple('id', _decode_u32), + SysViewEventParamSimple('lvl', _decode_u32), SysViewEventParamSimple('unused', _decode_u32)]), SYSVIEW_EVTID_NUMMODULES: ('svNumModules', [SysViewEventParamSimple('mod_cnt', _decode_u32)]), } @@ -486,8 +520,8 @@ class SysViewPredefinedEvent(SysViewEvent): """ see SysViewEvent.__init__() """ - self.name = 'SysViewPredefinedEvent' SysViewEvent.__init__(self, evt_id, reader, core_id, self._predef_events_fmt) + # self.name = 'SysViewPredefinedEvent' class SysViewOSEvent(SysViewEvent): @@ -498,8 +532,8 @@ class SysViewOSEvent(SysViewEvent): """ see SysViewEvent.__init__() """ - self.name = 'SysViewOSEvent' SysViewEvent.__init__(self, evt_id, reader, core_id, events_fmt_map) + # self.name = 'SysViewOSEvent' class SysViewHeapEvent(SysViewEvent): @@ -534,11 +568,11 @@ class SysViewHeapEvent(SysViewEvent): core_id : int see SysViewEvent.__init__() """ - self.name = 'SysViewHeapEvent' cur_events_map = {} for id in self.events_fmt: cur_events_map[events_off + id] = self.events_fmt[id] SysViewEvent.__init__(self, evt_id, reader, core_id, cur_events_map) + # self.name = 'SysViewHeapEvent' class SysViewTraceDataParser(apptrace.TraceDataProcessor): @@ -569,7 +603,7 @@ class SysViewTraceDataParser(apptrace.TraceDataProcessor): core_id : int id of the core this parser object relates to. """ - apptrace.TraceDataProcessor.__init__(self, print_events, keep_all_events=True) + apptrace.TraceDataProcessor.__init__(self, print_events=print_events, keep_all_events=True) self.sys_info = None self._last_ts = 0 self.irqs_info = {} @@ -670,6 +704,9 @@ class SysViewTraceDataParser(apptrace.TraceDataProcessor): else: return self.read_extension_event(evt_id, reader) + def event_supported(self, event): + return False + def on_new_event(self, event): """ Does essential processing of event. Must be called for every read event. @@ -701,6 +738,27 @@ class SysViewTraceDataParser(apptrace.TraceDataProcessor): apptrace.TraceDataProcessor.on_new_event(self, event) +class SysViewTraceDataExtEventParser(SysViewTraceDataParser): + def __init__(self, events_num, print_events=False, core_id=0): + """ + Constructor. + + Parameters + ---------- + print_events : bool + see apptrace.TraceDataProcessor.__init__() + core_id : int + id of the core this parser object relates to. + """ + SysViewTraceDataParser.__init__(self, core_id=core_id, print_events=print_events) + self.events_off = 0 + self.events_num = events_num + + def event_supported(self, event): + return False if (self.events_off < SYSVIEW_MODULE_EVENT_OFFSET or event.id < self.events_off or + event.id >= (self.events_off + self.events_num)) else True + + class SysViewMultiTraceDataParser(SysViewTraceDataParser): """ SystemView trace data parser supporting multiple event streams. @@ -794,7 +852,7 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor): """ Base SystemView trace data processor class. """ - def __init__(self, traces, print_events=False, keep_all_events=False): + def __init__(self, traces, root_proc=None, print_events=False, keep_all_events=False): """ Constructor. @@ -808,16 +866,20 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor): see apptrace.TraceDataProcessor.__init__() """ apptrace.TraceDataProcessor.__init__(self, print_events, keep_all_events) + self.event_ids = {} + self.name = "" + self.root_proc = root_proc if root_proc else self self.traces = {} self.ctx_stack = {} self.prev_ctx = {} + self.no_ctx_events = [] for t in traces: self.traces[t.core_id] = t # current context item is a tuple of task ID or IRQ num and 'in_irq' flag # empty list means IDLE context or self.start_ctx self.ctx_stack[t.core_id] = [] # context is undefined, we do not know have we started the tracing in task/IDLE or IRQ context - # there are three scenarious when we can start tracing: when core is in task, IDLE task or IRQ context + # in general there are three scenarious when we can start tracing: when core is in task, IDLE task or IRQ context self.prev_ctx[t.core_id] = None def _get_curr_context(self, core_id): @@ -878,13 +940,25 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor): return self.traces[core_id] return self.root_proc.get_trace_stream(core_id, stream_id) + def event_supported(self, e): + """ + Should be overriden in child class. + """ + return False + + def handle_event(self, e): + """ + Should be overriden in child class. + """ + pass + def print_report(self): """ see apptrace.TraceDataProcessor.print_report() """ apptrace.TraceDataProcessor.print_report(self) - def on_new_event(self, event): + def _process_event(self, event): """ Processes event. Keeps track of execution context on every core. @@ -952,8 +1026,35 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor): else: # the 1st context switching event after trace start is SYSVIEW_EVTID_TASK_STOP_READY, so we have been in task context self.prev_ctx[event.core_id] = SysViewEventContext(event.params['tid'].value, False, trace.tasks_info[event.params['tid'].value]) - # count events + + def on_new_event(self, event): + """ + Processes heap events. + """ + if self.root_proc == self: + SysViewTraceDataProcessor._process_event(self, event) + curr_ctx = self._get_curr_context(event.core_id) + if not curr_ctx: + # postpone events handling till their context is known + self.no_ctx_events.append(event) + return + event.in_irq = curr_ctx.irq + event.ctx_name = curr_ctx.name + # here we know the previous context: we switched from it or implied upon the 1st context switching event + prev_ctx = self._get_prev_context(event.core_id) + if len(self.no_ctx_events): + for cached_evt in self.no_ctx_events: + cached_evt.ctx_name = prev_ctx.name + cached_evt.in_irq = prev_ctx.irq + # count and save the event + apptrace.TraceDataProcessor.on_new_event(self, cached_evt) + if self.event_supported(event): + self.handle_event(event) + del self.no_ctx_events[:] + # count and save the event apptrace.TraceDataProcessor.on_new_event(self, event) + if self.event_supported(event): + self.handle_event(event) def merge_and_process(self): """ @@ -967,7 +1068,7 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor): self.on_new_event(event) -class SysViewMultiTraceDataProcessor(SysViewTraceDataProcessor): +class SysViewMultiStreamTraceDataProcessor(SysViewTraceDataProcessor): """ SystemView trace data processor supporting multiple event streams. """ @@ -975,7 +1076,7 @@ class SysViewMultiTraceDataProcessor(SysViewTraceDataProcessor): """ see SysViewTraceDataProcessor.__init__() """ - SysViewTraceDataProcessor.__init__(self, traces, print_events, keep_all_events) + SysViewTraceDataProcessor.__init__(self, traces, print_events=print_events, keep_all_events=keep_all_events) self.stream_procs = {} def add_stream_processor(self, stream_id, proc): @@ -1024,7 +1125,10 @@ class SysViewMultiTraceDataProcessor(SysViewTraceDataProcessor): Iterates over registered stream processors and prints their reports. """ SysViewTraceDataProcessor.print_report(self) - for stream_id in self.stream_procs: + # need to sort stream procs by keys to print reports in the same order regardless of Python version + stream_ids = list(self.stream_procs.keys()) + stream_ids.sort() + for stream_id in stream_ids: self.stream_procs[stream_id].print_report() def cleanup(self): @@ -1050,18 +1154,64 @@ class SysViewMultiTraceDataProcessor(SysViewTraceDataProcessor): self.stream_procs[stream_id].on_new_event(event) -class SysViewHeapTraceDataParser(SysViewTraceDataParser): +class SysViewTraceDataJsonEncoder(json.JSONEncoder): + JSON_TRACE_VER = "1.0" + + def default(self, obj): + global _sysview_events_map + global _os_events_map + if isinstance(obj, SysViewMultiStreamTraceDataProcessor): + json_event_ids = {"system": _sysview_events_map, "os": {}} + for eid in _os_events_map: + ename = _os_events_map[eid][0] + json_event_ids['os'][ename] = eid + for stream in obj.stream_procs.values(): + json_event_ids[stream.name] = stream.event_ids + json_events = [] + for e in obj.events: + for stream in obj.stream_procs.values(): + if stream.event_supported(e): + json_events.append(e) + break + # include also OS and pre-defined events + if isinstance(e, SysViewPredefinedEvent) or isinstance(e, SysViewOSEvent): + json_events.append(e) + return {"version": self.JSON_TRACE_VER, "streams": json_event_ids, "events": json_events} + if isinstance(obj, SysViewHeapEvent): + blk_size = 0 + if "size" in obj.params: + blk_size = obj.params["size"].value + blk_addr = "0x{:x}".format(obj.params["addr"].value) + callers = [] + for addr in obj.params['callers'].value: + callers.append('0x{:x}'.format(addr)) + return {"ctx_name": obj.ctx_name, "in_irq": obj.in_irq, "id": obj.id, "core_id": obj.core_id, + "ts": obj.ts, "addr": blk_addr, "size": blk_size, "callers": callers} + if isinstance(obj, SysViewPredefinedEvent) and obj.id == SYSVIEW_EVTID_PRINT_FORMATTED: + return {"ctx_name": obj.ctx_name, "in_irq": obj.in_irq, "id": obj.id, "core_id": obj.core_id, + "ts": obj.ts, "msg": obj.params["msg"].value, "lvl": obj.params["lvl"].value} + if isinstance(obj, SysViewEvent): + jobj = obj.to_jsonable() + # remove unused fields + if 'name' in jobj: + del jobj['name'] + if 'plen' in jobj: + del jobj['plen'] + return jobj + # Let the base class default method raise the TypeError + return json.JSONEncoder.default(self, obj) + + +class SysViewHeapTraceDataParser(SysViewTraceDataExtEventParser): """ SystemView trace data parser supporting heap events. """ def __init__(self, print_events=False, core_id=0): """ SystemView trace data parser supporting multiple event streams. - see SysViewTraceDataParser.__init__() + see SysViewTraceDataExtEventParser.__init__() """ - SysViewTraceDataParser.__init__(self, print_events, core_id) - self.events_off = 0 - self.events_num = len(SysViewHeapEvent.events_fmt.keys()) + SysViewTraceDataExtEventParser.__init__(self, events_num=len(SysViewHeapEvent.events_fmt.keys()), core_id=core_id, print_events=print_events) def read_extension_event(self, evt_id, reader): """ @@ -1087,57 +1237,34 @@ class SysViewHeapTraceDataProcessor(SysViewTraceDataProcessor, apptrace.BaseHeap """ SystemView trace data processor supporting heap events. """ - def __init__(self, toolchain_pref, elf_path, traces=[], print_events=False, print_heap_events=False): + def __init__(self, toolchain_pref, elf_path, root_proc=None, traces=[], print_events=False, print_heap_events=False): """ Constructor. see SysViewTraceDataProcessor.__init__() see apptrace.BaseHeapTraceDataProcessorImpl.__init__() """ - SysViewTraceDataProcessor.__init__(self, traces, print_events) + SysViewTraceDataProcessor.__init__(self, traces, root_proc=root_proc, print_events=print_events) apptrace.BaseHeapTraceDataProcessorImpl.__init__(self, print_heap_events) self.toolchain = toolchain_pref self.elf_path = elf_path - self.no_ctx_events = [] + # self.no_ctx_events = [] + self.name = "heap" + stream = self.root_proc.get_trace_stream(0, SysViewTraceDataParser.STREAMID_HEAP) + self.event_ids = {"alloc": stream.events_off, "free": stream.events_off + 1} - def on_new_event(self, event): - """ - Processes heap events. - """ - if self.root_proc == self: - SysViewTraceDataProcessor.on_new_event(self, event) + def event_supported(self, event): + heap_stream = self.root_proc.get_trace_stream(event.core_id, SysViewTraceDataParser.STREAMID_HEAP) + return heap_stream.event_supported(event) + + def handle_event(self, event): heap_stream = self.root_proc.get_trace_stream(event.core_id, SysViewTraceDataParser.STREAMID_HEAP) - if (heap_stream.events_off < SYSVIEW_MODULE_EVENT_OFFSET or event.id < heap_stream.events_off or - event.id >= (heap_stream.events_off + heap_stream.events_num)): - return - curr_ctx = self._get_curr_context(event.core_id) - if curr_ctx: - in_irq = curr_ctx.irq - ctx_name = curr_ctx.name - else: - in_irq = False - ctx_name = 'None' if (event.id - heap_stream.events_off) == 0: - heap_event = apptrace.HeapTraceEvent(ctx_name, in_irq, event.core_id, event.ts, - True, event.params['size'].value, event.params['addr'].value, - event.params['callers'].value, toolchain=self.toolchain, + heap_event = apptrace.HeapTraceEvent(event, True, toolchain=self.toolchain, elf_path=self.elf_path) else: - heap_event = apptrace.HeapTraceEvent(ctx_name, in_irq, event.core_id, event.ts, - False, 0, event.params['addr'].value, - event.params['callers'].value, toolchain=self.toolchain, + heap_event = apptrace.HeapTraceEvent(event, False, toolchain=self.toolchain, elf_path=self.elf_path) - if not curr_ctx: - # postpone events handling till their context is known - self.no_ctx_events.append(heap_event) - else: - # here we know the previous context: we switched from it or implied upon the 1st context switching event - prev_ctx = self._get_prev_context(event.core_id) - for cached_evt in self.no_ctx_events: - cached_evt.ctx_name = prev_ctx.name - cached_evt.in_irq = prev_ctx.irq - apptrace.BaseHeapTraceDataProcessorImpl.on_new_event(self, cached_evt) - del self.no_ctx_events[:] - apptrace.BaseHeapTraceDataProcessorImpl.on_new_event(self, heap_event) + apptrace.BaseHeapTraceDataProcessorImpl.on_new_event(self, heap_event) def print_report(self): """ @@ -1180,6 +1307,9 @@ class SysViewLogTraceDataParser(SysViewTraceDataParser): """ SystemView trace data parser supporting log events. """ + def event_supported(self, event): + return event.id == SYSVIEW_EVTID_PRINT_FORMATTED + def on_new_event(self, event): """ see SysViewTraceDataParser.on_new_event() @@ -1192,14 +1322,19 @@ class SysViewLogTraceDataProcessor(SysViewTraceDataProcessor, apptrace.BaseLogTr """ SystemView trace data processor supporting heap events. """ - def __init__(self, traces=[], print_events=False, print_log_events=False): + def __init__(self, traces=[], root_proc=None, print_events=False, print_log_events=False): """ Constructor. see SysViewTraceDataProcessor.__init__() see apptrace.BaseLogTraceDataProcessorImpl.__init__() """ - SysViewTraceDataProcessor.__init__(self, traces, print_events) + SysViewTraceDataProcessor.__init__(self, traces, root_proc=root_proc, print_events=print_events) apptrace.BaseLogTraceDataProcessorImpl.__init__(self, print_log_events) + self.name = "log" + self.event_ids = {"print": SYSVIEW_EVTID_PRINT_FORMATTED} + + def event_supported(self, event): + return event.id == SYSVIEW_EVTID_PRINT_FORMATTED def on_new_event(self, event): """ diff --git a/tools/esp_app_trace/sysviewtrace_proc.py b/tools/esp_app_trace/sysviewtrace_proc.py index d94555982..95fd64313 100755 --- a/tools/esp_app_trace/sysviewtrace_proc.py +++ b/tools/esp_app_trace/sysviewtrace_proc.py @@ -24,22 +24,34 @@ import sys import os.path import signal import traceback +import logging +import json import espytrace.apptrace as apptrace import espytrace.sysview as sysview def main(): + verbosity_levels = [ + logging.CRITICAL, + logging.ERROR, + logging.WARNING, + logging.INFO, + logging.DEBUG + ] + parser = argparse.ArgumentParser(description='ESP32 SEGGER SystemView Trace Parsing Tool') parser.add_argument('trace_sources', help='Trace data sources. Format: [file://]/path/to/file.', nargs='+', type=str) - parser.add_argument('elf_file', help='Path to program ELF file.', type=str) + parser.add_argument('--elf-file', '-b', help='Path to program ELF file.', type=str, default='') parser.add_argument('--tmo', '-w', help='Data wait timeout in sec. -1: infinite, 0: no wait', type=int, default=0) parser.add_argument('--dump-events', '-d', help='Dump all events.', action='store_true') parser.add_argument('--print-events', '-p', help='Print events of selected types. By default only reports are printed', action='store_true') parser.add_argument('--include-events', '-i', help='Events types to be included into report.', type=str, choices=['heap', 'log', 'all'], default='all') parser.add_argument('--toolchain', '-t', help='Toolchain prefix.', type=str, default='xtensa-esp32-elf-') parser.add_argument('--events-map', '-e', help='Events map file.', type=str, default=os.path.join(os.path.dirname(__file__), 'SYSVIEW_FreeRTOS.txt')) + parser.add_argument('--to-json', '-j', help='Print JSON.', action='store_true', default=False) + parser.add_argument('--verbose', '-v', help='Verbosity level. Default 1', choices=range(0, len(verbosity_levels)), type=int, default=1) args = parser.parse_args() def sig_int_handler(signum, frame): @@ -56,6 +68,8 @@ def main(): elif args.include_events == 'log': include_events['log'] = True + logging.basicConfig(level=verbosity_levels[args.verbose], format='[%(levelname)s] %(message)s') + # parse trace files parsers = [] for i, trace_source in enumerate(args.trace_sources): @@ -69,21 +83,22 @@ def main(): sysview.SysViewLogTraceDataParser(print_events=False, core_id=i)) parsers.append(parser) except Exception as e: - print("Failed to create data parser ({})!".format(e)) + logging.error("Failed to create data parser (%s)!", e) traceback.print_exc() sys.exit(2) reader = apptrace.reader_create(trace_source, args.tmo) if not reader: - print("Failed to create trace reader!") + logging.error("Failed to create trace reader!") sys.exit(2) try: - print("Parse trace from '{}'...".format(trace_source)) + # logging.info("Parse trace from '{}'...".format(trace_source)) + logging.info("Parse trace from '%s'...", trace_source) sysview.parse_trace(reader, parser, args.events_map) - print("Parsing completed.") + logging.info("Parsing completed.") except (apptrace.ReaderTimeoutError, apptrace.ReaderShutdownRequest) as e: - print("Stop parsing trace. ({})".format(e)) + logging.info("Stop parsing trace. (%s)", e) except Exception as e: - print("Failed to parse trace ({})!".format(e)) + logging.error("Failed to parse trace (%s)!", e) parser.cleanup() traceback.print_exc() sys.exit(2) @@ -92,27 +107,32 @@ def main(): # merge and process traces try: - proc = sysview.SysViewMultiTraceDataProcessor(traces=parsers, print_events=args.dump_events) + proc = sysview.SysViewMultiStreamTraceDataProcessor(traces=parsers, print_events=args.dump_events, keep_all_events=True if args.to_json else False) if include_events['heap']: proc.add_stream_processor(sysview.SysViewTraceDataParser.STREAMID_HEAP, - sysview.SysViewHeapTraceDataProcessor(args.toolchain, args.elf_file, print_heap_events=args.print_events)) + sysview.SysViewHeapTraceDataProcessor(args.toolchain, args.elf_file, root_proc=proc, print_heap_events=args.print_events)) if include_events['log']: proc.add_stream_processor(sysview.SysViewTraceDataParser.STREAMID_LOG, - sysview.SysViewLogTraceDataProcessor(print_log_events=args.print_events)) + sysview.SysViewLogTraceDataProcessor(root_proc=proc, print_log_events=args.print_events)) except Exception as e: - print("Failed to create data processor ({})!".format(e)) + logging.error("Failed to create data processor (%s)!", e) traceback.print_exc() sys.exit(2) + try: - print("Process events from '{}'...".format(args.trace_sources)) + logging.info("Process events from '%s'...", args.trace_sources) proc.merge_and_process() - print("Processing completed.") + logging.info("Processing completed.") except Exception as e: - print("Failed to process trace ({})!".format(e)) + logging.error("Failed to process trace (%s)!", e) traceback.print_exc() sys.exit(2) finally: - proc.print_report() + if args.to_json: + print(json.dumps(proc, cls=sysview.SysViewTraceDataJsonEncoder, indent=4, separators=(',', ': '), sort_keys=True)) + else: + proc.print_report() + proc.cleanup() if __name__ == '__main__': diff --git a/tools/esp_app_trace/test/sysview/compare_json.py b/tools/esp_app_trace/test/sysview/compare_json.py new file mode 100755 index 000000000..e53cb4a71 --- /dev/null +++ b/tools/esp_app_trace/test/sysview/compare_json.py @@ -0,0 +1,16 @@ +#!/usr/bin/env python + +import json +import sys + +if len(sys.argv) < 3: + sys.exit(-1) + +objs = [] +for i in range(1, len(sys.argv)): + f = open(sys.argv[i]) + objs.append(json.load(f)) + +for i in range(1, len(objs)): + if objs[i - 1] != objs[i]: + sys.exit(-1) diff --git a/tools/esp_app_trace/test/sysview/expected_output b/tools/esp_app_trace/test/sysview/expected_output index 64c3a3948..8d90f69d0 100644 --- a/tools/esp_app_trace/test/sysview/expected_output +++ b/tools/esp_app_trace/test/sysview/expected_output @@ -1,8 +1,3 @@ -Parse trace from 'cpu0.svdat'... -Stop parsing trace. (Timeout 0.000000 sec while reading 1 bytes!) -Parse trace from 'cpu1.svdat'... -Stop parsing trace. (Timeout 0.000000 sec while reading 1 bytes!) -Process events from '['cpu0.svdat', 'cpu1.svdat']'... EVENT[0]: 0.000000000 - core[0].svTraceStart(10), plen 0: [] EVENT[1]: 0.000000000 - core[1].svTraceStart(10), plen 0: [] EVENT[2]: 0.000010950 - core[0].svInit(24), plen 14: [sys_freq: 40000000, cpu_freq: 160000000, ram_base: 1061158912, id_shift: 0] @@ -417,7 +412,6 @@ EVENT[354]: 0.148825750 - core[0].vTaskDelay(34), plen 1: [xTicksToDelay: 1] EVENT[355]: 0.148833200 - core[0].svTaskStopReady(7), plen 0: [tid: 12291908, cause: 4] EVENT[356]: 0.148839250 - core[0].svTraceStop(11), plen 0: [] EVENT[357]: 0.148839250 - core[1].svTraceStop(11), plen 0: [] -Processing completed. Processed 358 events =============== LOG TRACE REPORT =============== Processed 0 log messages. diff --git a/tools/esp_app_trace/test/sysview/expected_output.json b/tools/esp_app_trace/test/sysview/expected_output.json new file mode 100644 index 000000000..bed6bc6f7 --- /dev/null +++ b/tools/esp_app_trace/test/sysview/expected_output.json @@ -0,0 +1,3960 @@ +{ + "events": [ + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 10, + "in_irq": true, + "params": {}, + "ts": 0 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 10, + "in_irq": true, + "params": {}, + "ts": 0 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 24, + "in_irq": true, + "params": { + "cpu_freq": 160000000, + "id_shift": 0, + "ram_base": 1061158912, + "sys_freq": 40000000 + }, + "ts": 1.095e-05 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 24, + "in_irq": true, + "params": { + "cpu_freq": 160000000, + "id_shift": 0, + "ram_base": 1061158912, + "sys_freq": 40000000 + }, + "ts": 1.095e-05 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "N=FreeRTOS Application,D=ESP32,C=Xtensa,O=FreeRTOS" + }, + "ts": 2.48e-05 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "N=FreeRTOS Application,D=ESP32,C=Xtensa,O=FreeRTOS" + }, + "ts": 2.48e-05 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#5=SysTick" + }, + "ts": 5.165e-05 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#5=SysTick" + }, + "ts": 5.165e-05 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#6=WIFI_MAC" + }, + "ts": 0.00010415 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#6=WIFI_MAC" + }, + "ts": 0.00010415 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#7=WIFI_NMI" + }, + "ts": 0.0001211 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#7=WIFI_NMI" + }, + "ts": 0.0001211 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#8=WIFI_BB" + }, + "ts": 0.000138125 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#8=WIFI_BB" + }, + "ts": 0.000138125 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#9=BT_MAC" + }, + "ts": 0.000154825 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#9=BT_MAC" + }, + "ts": 0.000154825 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#10=BT_BB" + }, + "ts": 0.00019335 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#10=BT_BB" + }, + "ts": 0.00019335 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#11=BT_BB_NMI" + }, + "ts": 0.000212875 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#11=BT_BB_NMI" + }, + "ts": 0.000212875 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#12=RWBT" + }, + "ts": 0.000231625 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#12=RWBT" + }, + "ts": 0.000231625 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#13=RWBLE" + }, + "ts": 0.00025025 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#13=RWBLE" + }, + "ts": 0.00025025 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#14=RWBT_NMI" + }, + "ts": 0.00026945 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#14=RWBT_NMI" + }, + "ts": 0.00026945 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#15=RWBLE_NMI" + }, + "ts": 0.000288925 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#15=RWBLE_NMI" + }, + "ts": 0.000288925 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#16=SLC0" + }, + "ts": 0.000310575 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#16=SLC0" + }, + "ts": 0.000310575 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#17=SLC1" + }, + "ts": 0.00032915 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#17=SLC1" + }, + "ts": 0.00032915 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#18=UHCI0" + }, + "ts": 0.000347675 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#18=UHCI0" + }, + "ts": 0.000347675 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#19=UHCI1" + }, + "ts": 0.000366225 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#19=UHCI1" + }, + "ts": 0.000366225 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#20=TG0_T0_LEVEL" + }, + "ts": 0.00038635 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#20=TG0_T0_LEVEL" + }, + "ts": 0.00038635 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#21=TG0_T1_LEVEL" + }, + "ts": 0.000406575 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#21=TG0_T1_LEVEL" + }, + "ts": 0.000406575 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#22=TG0_WDT_LEVEL" + }, + "ts": 0.0004273 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#22=TG0_WDT_LEVEL" + }, + "ts": 0.0004273 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#23=TG0_LACT_LEVEL" + }, + "ts": 0.000448 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#23=TG0_LACT_LEVEL" + }, + "ts": 0.000448 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#24=TG1_T0_LEVEL" + }, + "ts": 0.00046825 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#24=TG1_T0_LEVEL" + }, + "ts": 0.00046825 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#25=TG1_T1_LEVEL" + }, + "ts": 0.0004885 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#25=TG1_T1_LEVEL" + }, + "ts": 0.0004885 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#26=TG1_WDT_LEVEL" + }, + "ts": 0.000508975 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#26=TG1_WDT_LEVEL" + }, + "ts": 0.000508975 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#27=TG1_LACT_LEVEL" + }, + "ts": 0.00052985 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#27=TG1_LACT_LEVEL" + }, + "ts": 0.00052985 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#28=GPIO" + }, + "ts": 0.000548375 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#28=GPIO" + }, + "ts": 0.000548375 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#29=GPIO_NMI" + }, + "ts": 0.000570825 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#29=GPIO_NMI" + }, + "ts": 0.000570825 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#30=FROM_CPU0" + }, + "ts": 0.000590425 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#30=FROM_CPU0" + }, + "ts": 0.000590425 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#31=FROM_CPU1" + }, + "ts": 0.00061 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#31=FROM_CPU1" + }, + "ts": 0.00061 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#32=FROM_CPU2" + }, + "ts": 0.000629625 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#32=FROM_CPU2" + }, + "ts": 0.000629625 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#33=FROM_CPU3" + }, + "ts": 0.000649425 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#33=FROM_CPU3" + }, + "ts": 0.000649425 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#34=SPI0" + }, + "ts": 0.000667975 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#34=SPI0" + }, + "ts": 0.000667975 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#35=SPI1" + }, + "ts": 0.0006865 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#35=SPI1" + }, + "ts": 0.0006865 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#36=SPI2" + }, + "ts": 0.000704825 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#36=SPI2" + }, + "ts": 0.000704825 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#37=SPI3" + }, + "ts": 0.0007231 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#37=SPI3" + }, + "ts": 0.0007231 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#38=I2S0" + }, + "ts": 0.00074155 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#38=I2S0" + }, + "ts": 0.00074155 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#39=I2S1" + }, + "ts": 0.00076 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#39=I2S1" + }, + "ts": 0.00076 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#40=UART0" + }, + "ts": 0.000778475 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#40=UART0" + }, + "ts": 0.000778475 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#41=UART1" + }, + "ts": 0.00079705 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#41=UART1" + }, + "ts": 0.00079705 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#42=UART2" + }, + "ts": 0.000815625 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#42=UART2" + }, + "ts": 0.000815625 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#43=SDIO_HOST" + }, + "ts": 0.000835 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#43=SDIO_HOST" + }, + "ts": 0.000835 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#44=ETH_MAC" + }, + "ts": 0.000854075 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#44=ETH_MAC" + }, + "ts": 0.000854075 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#45=PWM0" + }, + "ts": 0.0008756 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#45=PWM0" + }, + "ts": 0.0008756 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#46=PWM1" + }, + "ts": 0.00089385 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#46=PWM1" + }, + "ts": 0.00089385 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#47=PWM2" + }, + "ts": 0.000912375 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#47=PWM2" + }, + "ts": 0.000912375 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#48=PWM3" + }, + "ts": 0.00093095 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#48=PWM3" + }, + "ts": 0.00093095 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#49=LEDC" + }, + "ts": 0.000949375 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#49=LEDC" + }, + "ts": 0.000949375 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#50=EFUSE" + }, + "ts": 0.000968075 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#50=EFUSE" + }, + "ts": 0.000968075 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#51=CAN" + }, + "ts": 0.000986275 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#51=CAN" + }, + "ts": 0.000986275 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#52=RTC_CORE" + }, + "ts": 0.001005625 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#52=RTC_CORE" + }, + "ts": 0.001005625 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#53=RMT" + }, + "ts": 0.0010237 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#53=RMT" + }, + "ts": 0.0010237 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#54=PCNT" + }, + "ts": 0.00104205 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#54=PCNT" + }, + "ts": 0.00104205 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#55=I2C_EXT0" + }, + "ts": 0.0010615 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#55=I2C_EXT0" + }, + "ts": 0.0010615 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#56=I2C_EXT1" + }, + "ts": 0.0010811 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#56=I2C_EXT1" + }, + "ts": 0.0010811 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#57=RSA" + }, + "ts": 0.001099425 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#57=RSA" + }, + "ts": 0.001099425 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#58=SPI1_DMA" + }, + "ts": 0.001118625 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#58=SPI1_DMA" + }, + "ts": 0.001118625 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#59=SPI2_DMA" + }, + "ts": 0.001137775 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#59=SPI2_DMA" + }, + "ts": 0.001137775 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#60=SPI3_DMA" + }, + "ts": 0.00115695 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#60=SPI3_DMA" + }, + "ts": 0.00115695 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#61=WDT" + }, + "ts": 0.001175175 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#61=WDT" + }, + "ts": 0.001175175 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#62=TIMER1" + }, + "ts": 0.0011973 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#62=TIMER1" + }, + "ts": 0.0011973 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#63=TIMER2" + }, + "ts": 0.00121625 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#63=TIMER2" + }, + "ts": 0.00121625 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#64=TG0_T0_EDGE" + }, + "ts": 0.001236175 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#64=TG0_T0_EDGE" + }, + "ts": 0.001236175 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#65=TG0_T1_EDGE" + }, + "ts": 0.001256275 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#65=TG0_T1_EDGE" + }, + "ts": 0.001256275 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#66=TG0_WDT_EDGE" + }, + "ts": 0.001276675 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#66=TG0_WDT_EDGE" + }, + "ts": 0.001276675 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#67=TG0_LACT_EDGE" + }, + "ts": 0.001297375 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#67=TG0_LACT_EDGE" + }, + "ts": 0.001297375 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#68=TG1_T0_EDGE" + }, + "ts": 0.001317425 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#68=TG1_T0_EDGE" + }, + "ts": 0.001317425 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#69=TG1_T1_EDGE" + }, + "ts": 0.00133765 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#69=TG1_T1_EDGE" + }, + "ts": 0.00133765 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#70=TG1_WDT_EDGE" + }, + "ts": 0.00135795 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#70=TG1_WDT_EDGE" + }, + "ts": 0.00135795 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#71=TG1_LACT_EDGE" + }, + "ts": 0.001378625 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#71=TG1_LACT_EDGE" + }, + "ts": 0.001378625 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#72=MMU_IA" + }, + "ts": 0.0013975 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#72=MMU_IA" + }, + "ts": 0.0013975 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#73=MPU_IA" + }, + "ts": 0.001416425 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#73=MPU_IA" + }, + "ts": 0.001416425 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#74=CACHE_IA" + }, + "ts": 0.00143555 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 14, + "in_irq": true, + "params": { + "desc": "I#74=CACHE_IA" + }, + "ts": 0.00143555 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 13, + "in_irq": true, + "params": { + "time": 10000 + }, + "ts": 0.00144195 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 13, + "in_irq": true, + "params": { + "time": 10000 + }, + "ts": 0.00144195 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "esp_timer", + "prio": 22, + "tid": 12253880 + }, + "ts": 0.0016474 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "esp_timer", + "prio": 22, + "tid": 12253880 + }, + "ts": 0.0016474 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073408692, + "sz": 3436, + "tid": 12253880, + "unused": 0 + }, + "ts": 0.001652 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073408692, + "sz": 3436, + "tid": 12253880, + "unused": 0 + }, + "ts": 0.001652 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "ipc0", + "prio": 24, + "tid": 12254636 + }, + "ts": 0.00173855 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "ipc0", + "prio": 24, + "tid": 12254636 + }, + "ts": 0.00173855 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073430180, + "sz": 1388, + "tid": 12254636, + "unused": 0 + }, + "ts": 0.00174275 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073430180, + "sz": 1388, + "tid": 12254636, + "unused": 0 + }, + "ts": 0.00174275 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "ipc1", + "prio": 24, + "tid": 12275372 + }, + "ts": 0.001828975 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "ipc1", + "prio": 24, + "tid": 12275372 + }, + "ts": 0.001828975 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073432232, + "sz": 1384, + "tid": 12275372, + "unused": 0 + }, + "ts": 0.001833225 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073432232, + "sz": 1384, + "tid": 12275372, + "unused": 0 + }, + "ts": 0.001833225 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "blink_task", + "prio": 5, + "tid": 12291908 + }, + "ts": 0.001871225 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "blink_task", + "prio": 5, + "tid": 12291908 + }, + "ts": 0.001871225 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073448452, + "sz": 524, + "tid": 12291908, + "unused": 0 + }, + "ts": 0.00187565 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073448452, + "sz": 524, + "tid": 12291908, + "unused": 0 + }, + "ts": 0.00187565 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "main", + "prio": 1, + "tid": 12282660 + }, + "ts": 0.0020708 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "main", + "prio": 1, + "tid": 12282660 + }, + "ts": 0.0020708 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073437472, + "sz": 3296, + "tid": 12282660, + "unused": 0 + }, + "ts": 0.0020752 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073437472, + "sz": 3296, + "tid": 12282660, + "unused": 0 + }, + "ts": 0.0020752 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "IDLE0", + "prio": 0, + "tid": 12284560 + }, + "ts": 0.002153375 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "IDLE0", + "prio": 0, + "tid": 12284560 + }, + "ts": 0.002153375 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073441932, + "sz": 1236, + "tid": 12284560, + "unused": 0 + }, + "ts": 0.00215785 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073441932, + "sz": 1236, + "tid": 12284560, + "unused": 0 + }, + "ts": 0.00215785 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "IDLE1", + "prio": 0, + "tid": 12286460 + }, + "ts": 0.00222895 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "IDLE1", + "prio": 0, + "tid": 12286460 + }, + "ts": 0.00222895 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073443832, + "sz": 1112, + "tid": 12286460, + "unused": 0 + }, + "ts": 0.00223325 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073443832, + "sz": 1112, + "tid": 12286460, + "unused": 0 + }, + "ts": 0.00223325 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "Tmr Svc", + "prio": 1, + "tid": 12289116 + }, + "ts": 0.002319675 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "Tmr Svc", + "prio": 1, + "tid": 12289116 + }, + "ts": 0.002319675 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073445976, + "sz": 1384, + "tid": 12289116, + "unused": 0 + }, + "ts": 0.0023241 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073445976, + "sz": 1384, + "tid": 12289116, + "unused": 0 + }, + "ts": 0.0023241 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "blink_task2", + "prio": 5, + "tid": 12294320 + }, + "ts": 0.0024312 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 9, + "in_irq": true, + "params": { + "name": "blink_task2", + "prio": 5, + "tid": 12294320 + }, + "ts": 0.0024312 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073451180, + "sz": 1748, + "tid": 12294320, + "unused": 0 + }, + "ts": 0.00243875 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 21, + "in_irq": true, + "params": { + "base": 1073451180, + "sz": 1748, + "tid": 12294320, + "unused": 0 + }, + "ts": 0.00243875 + }, + { + "core_id": 0, + "ctx_name": "IRQ_oncore1", + "id": 27, + "in_irq": true, + "params": { + "mod_cnt": 0 + }, + "ts": 0.00244615 + }, + { + "core_id": 1, + "ctx_name": "IRQ_oncore1", + "id": 27, + "in_irq": true, + "params": { + "mod_cnt": 0 + }, + "ts": 0.00244615 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.002484225 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 7, + "in_irq": false, + "params": { + "cause": 4, + "tid": 12291908 + }, + "ts": 0.002496125 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.002508025 + }, + { + "core_id": 0, + "ctx_name": "FROM_CPU0", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 30 + }, + "ts": 0.00251635 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12294320 + }, + "ts": 0.002524325 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.00253235 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.0025412 + }, + { + "core_id": 0, + "ctx_name": "main", + "id": 4, + "in_irq": false, + "params": { + "tid": 12282660 + }, + "ts": 0.002548475 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.002556375 + }, + { + "core_id": 0, + "ctx_name": "main", + "id": 33, + "in_irq": false, + "params": { + "xTaskToDelete": 12282660 + }, + "ts": 0.00256445 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.0025777 + }, + { + "core_id": 0, + "ctx_name": "FROM_CPU0", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 30 + }, + "ts": 0.002585225 + }, + { + "core_id": 0, + "ctx_name": "main", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.00259295 + }, + { + "core_id": 0, + "ctx_name": "main", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.00260595 + }, + { + "core_id": 0, + "ctx_name": "SysTick", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 5 + }, + "ts": 0.00881955 + }, + { + "core_id": 0, + "ctx_name": "SysTick", + "id": 6, + "in_irq": true, + "params": { + "tid": 12291908 + }, + "ts": 0.008828075 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 6, + "in_irq": false, + "params": { + "tid": 12291908 + }, + "ts": 0.008828075 + }, + { + "core_id": 0, + "ctx_name": "main", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.008837475 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 4, + "in_irq": false, + "params": { + "tid": 12291908 + }, + "ts": 0.00885045 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 22, + "in_irq": false, + "params": { + "desc": "ESP32 SystemView Heap Tracing Module", + "evt_off": 512, + "mod_id": 0 + }, + "ts": 0.00887265 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 22, + "in_irq": false, + "params": { + "desc": "ESP32 SystemView Heap Tracing Module", + "evt_off": 512, + "mod_id": 0 + }, + "ts": 0.00887265 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.008886175 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.008886175 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.008897425 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.00890615 + }, + { + "addr": "0x3ffb8e08", + "callers": [ + "0x400d1e63", + "0x40087834" + ], + "core_id": 0, + "ctx_name": "blink_task", + "id": 512, + "in_irq": false, + "size": 64, + "ts": 0.0089199 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.00892825 + }, + { + "addr": "0x3ffb8e4c", + "callers": [ + "0x40087f1e", + "0x40088183" + ], + "core_id": 0, + "ctx_name": "blink_task", + "id": 512, + "in_irq": false, + "size": 80, + "ts": 0.00895795 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 47, + "in_irq": false, + "params": { + "ucQueueType": 4, + "uxItemSize": 0, + "uxQueueLength": 1 + }, + "ts": 0.00896725 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.0089773 + }, + { + "addr": "0x3ffb8ea0", + "callers": [ + "0x400d1da6", + "0x40087834" + ], + "core_id": 1, + "ctx_name": "blink_task2", + "id": 512, + "in_irq": false, + "size": 65, + "ts": 0.008984625 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.008995725 + }, + { + "core_id": 1, + "ctx_name": "SysTick", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 5 + }, + "ts": 0.009010075 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.009018025 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.0090319 + }, + { + "addr": "0x3ffb5014", + "callers": [ + "0x40087f1e", + "0x40088183" + ], + "core_id": 0, + "ctx_name": "blink_task", + "id": 512, + "in_irq": false, + "size": 80, + "ts": 0.0090896 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12294320 + }, + "ts": 0.009098175 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 47, + "in_irq": false, + "params": { + "ucQueueType": 4, + "uxItemSize": 0, + "uxQueueLength": 1 + }, + "ts": 0.0091063 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.009113825 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.0091216 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.009129 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.0091379 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.009145425 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.0091696 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.009185225 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009195125 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009195125 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.009207 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.009215575 + }, + { + "addr": "0x3ffb5068", + "callers": [ + "0x400d1e73", + "0x40087834" + ], + "core_id": 0, + "ctx_name": "blink_task", + "id": 512, + "in_irq": false, + "size": 96, + "ts": 0.009223275 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.00923105 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.009241875 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12294320 + }, + "ts": 0.009257225 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.0092692 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.009278275 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.009286275 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.00930345 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.00931095 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.009329625 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009339525 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009339525 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.009351425 + }, + { + "addr": "0x3ffb8e08", + "callers": [ + "0x400d1e80", + "0x40087834" + ], + "core_id": 0, + "ctx_name": "blink_task", + "id": 513, + "in_irq": false, + "size": 0, + "ts": 0.00935945 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.0093678 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.00937895 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.00938745 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12294320 + }, + "ts": 0.009402575 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.0094149 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.009423125 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.00943025 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.009445425 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.009453075 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.009469225 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009479025 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009479025 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.00949095 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.009499475 + }, + { + "addr": "0x3ffb8e08", + "callers": [ + "0x400d1e8f", + "0x40087834" + ], + "core_id": 0, + "ctx_name": "blink_task", + "id": 512, + "in_irq": false, + "size": 10, + "ts": 0.0095076 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.0095153 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.0095261 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12294320 + }, + "ts": 0.00954155 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.00955385 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.0095611 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.0095684 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.009585075 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.009593375 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.00960915 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009621875 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009621875 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.009633775 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.0096423 + }, + { + "addr": "0x3ffb8e18", + "callers": [ + "0x400d1e9c", + "0x40087834" + ], + "core_id": 0, + "ctx_name": "blink_task", + "id": 512, + "in_irq": false, + "size": 23, + "ts": 0.009649475 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.009657875 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.009666025 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12294320 + }, + "ts": 0.0096815 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.009693375 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.0097028 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.00971055 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.009726725 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.010504825 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.01052065 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.01053055 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.01053055 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.0105424 + }, + { + "addr": "0x3ffb8e18", + "callers": [ + "0x400d1eab", + "0x40087834" + ], + "core_id": 0, + "ctx_name": "blink_task", + "id": 513, + "in_irq": false, + "size": 0, + "ts": 0.010550025 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.01055745 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.0105697 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.0105777 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12294320 + }, + "ts": 0.010592825 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.01060595 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.010613575 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.0106209 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.01063705 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.01224095 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.012256775 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.01226665 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 6, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.01226665 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.01228135 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12291908 + }, + "ts": 0.012289475 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.01229745 + }, + { + "core_id": 0, + "ctx_name": "FROM_CPU0", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 30 + }, + "ts": 0.01230635 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.012312875 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.0123207 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.01232895 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.0123381 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.012640475 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.01493185 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.014963325 + }, + { + "addr": "0x3ffb50cc", + "callers": [ + "0x400d1db7", + "0x40087834" + ], + "core_id": 1, + "ctx_name": "blink_task2", + "id": 512, + "in_irq": false, + "size": 97, + "ts": 0.01498415 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.0149974 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.01503105 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.0176228 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.017638675 + }, + { + "addr": "0x3ffb8ea0", + "callers": [ + "0x400d1dc4", + "0x40087834" + ], + "core_id": 1, + "ctx_name": "blink_task2", + "id": 513, + "in_irq": false, + "size": 0, + "ts": 0.017656375 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.017674025 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.0177017 + }, + { + "core_id": 0, + "ctx_name": "SysTick", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 5 + }, + "ts": 0.01881955 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.018829625 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.01884475 + }, + { + "core_id": 1, + "ctx_name": "SysTick", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 5 + }, + "ts": 0.019010075 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.01901795 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 4, + "in_irq": false, + "params": { + "tid": 12294320 + }, + "ts": 0.0190332 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.019358925 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.0193746 + }, + { + "addr": "0x3ffb8e18", + "callers": [ + "0x400d1dd3", + "0x40087834" + ], + "core_id": 1, + "ctx_name": "blink_task2", + "id": 512, + "in_irq": false, + "size": 11, + "ts": 0.019395425 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.0194126 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.01944625 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.0220499 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.022065775 + }, + { + "addr": "0x3ffb8e28", + "callers": [ + "0x400d1de0", + "0x40087834" + ], + "core_id": 1, + "ctx_name": "blink_task2", + "id": 512, + "in_irq": false, + "size": 24, + "ts": 0.022086625 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.022103925 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.02213755 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.02474085 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.024756725 + }, + { + "addr": "0x3ffb8e28", + "callers": [ + "0x400d1def", + "0x40087834" + ], + "core_id": 1, + "ctx_name": "blink_task2", + "id": 513, + "in_irq": false, + "size": 0, + "ts": 0.024770475 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12291660, + "xTicksToWait": 4294967295 + }, + "ts": 0.02479175 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 49, + "in_irq": false, + "params": { + "pvBuffer": 3233808384, + "xJustPeek": 0, + "xQueue": 12275732, + "xTicksToWait": 4294967295 + }, + "ts": 0.0248195 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12275732, + "xTicksToWait": 0 + }, + "ts": 0.02647695 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 53, + "in_irq": false, + "params": { + "pvItemToQueue": 0, + "xCopyPosition": 0, + "xQueue": 12291660, + "xTicksToWait": 0 + }, + "ts": 0.0264957 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 6, + "in_irq": false, + "params": { + "tid": 12291908 + }, + "ts": 0.026506975 + }, + { + "core_id": 1, + "ctx_name": "blink_task2", + "id": 6, + "in_irq": false, + "params": { + "tid": 12291908 + }, + "ts": 0.026506975 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 7, + "in_irq": false, + "params": { + "cause": 27, + "tid": 12294320 + }, + "ts": 0.026518525 + }, + { + "core_id": 0, + "ctx_name": "FROM_CPU0", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 30 + }, + "ts": 0.026526625 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.026535575 + }, + { + "core_id": 1, + "ctx_name": "FROM_CPU1", + "id": 2, + "in_irq": true, + "params": { + "irq_num": 31 + }, + "ts": 0.026544075 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 4, + "in_irq": false, + "params": { + "tid": 12291908 + }, + "ts": 0.02655165 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 18, + "in_irq": false, + "params": {}, + "ts": 0.0265595 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 17, + "in_irq": false, + "params": {}, + "ts": 0.148816725 + }, + { + "core_id": 0, + "ctx_name": "blink_task", + "id": 34, + "in_irq": false, + "params": { + "xTicksToDelay": 1 + }, + "ts": 0.14882575 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 7, + "in_irq": false, + "params": { + "cause": 4, + "tid": 12291908 + }, + "ts": 0.1488332 + }, + { + "core_id": 0, + "ctx_name": "IDLE0", + "id": 11, + "in_irq": false, + "params": {}, + "ts": 0.14883925 + }, + { + "core_id": 1, + "ctx_name": "IDLE1", + "id": 11, + "in_irq": false, + "params": {}, + "ts": 0.14883925 + } + ], + "streams": { + "heap": { + "alloc": 512, + "free": 513 + }, + "log": { + "print": 26 + }, + "os": { + "eTaskConfirmSleepModeStatus": 157, + "eTaskGetState": 130, + "esp_sysview_heap_trace_alloc": 512, + "esp_sysview_heap_trace_free": 513, + "pcTaskGetTaskName": 137, + "pcTimerGetTimerName": 165, + "pvTaskGetThreadLocalStoragePointer": 142, + "pvTimerGetTimerID": 159, + "ulTaskNotifyTake": 37, + "uxEventGroupGetNumber": 200, + "uxListRemove": 193, + "uxQueueMessagesWaiting": 168, + "uxQueueMessagesWaitingFromISR": 170, + "uxQueueSpacesAvailable": 169, + "uxTaskGetNumberOfTasks": 136, + "uxTaskGetStackHighWaterMark": 138, + "uxTaskGetSystemState": 145, + "uxTaskGetTaskNumber": 155, + "uxTaskPriorityGet": 129, + "uxTaskPriorityGetFromISR": 56, + "vEventGroupDelete": 199, + "vListInitialise": 189, + "vListInitialiseItem": 190, + "vListInsert": 191, + "vListInsertEnd": 192, + "vQueueAddToRegistry": 52, + "vQueueDelete": 48, + "vQueueUnregisterQueue": 182, + "vTaskAllocateMPURegions": 128, + "vTaskDelay": 34, + "vTaskDelayUntil": 35, + "vTaskDelete": 33, + "vTaskEndScheduler": 132, + "vTaskGetRunTimeStats": 147, + "vTaskList": 146, + "vTaskMissedYield": 152, + "vTaskNotifyGiveFromISR": 38, + "vTaskPriorityInherit": 39, + "vTaskPrioritySet": 55, + "vTaskResume": 40, + "vTaskSetApplicationTaskTag": 139, + "vTaskSetTaskNumber": 156, + "vTaskSetThreadLocalStoragePointer": 141, + "vTaskSetTimeOutState": 150, + "vTaskStartScheduler": 131, + "vTaskStepTick": 41, + "vTaskSuspend": 36, + "vTaskSuspendAll": 133, + "vTimerSetTimerID": 160, + "xEventGroupClearBits": 196, + "xEventGroupClearBitsFromISR": 58, + "xEventGroupCreate": 194, + "xEventGroupGetBitsFromISR": 60, + "xEventGroupSetBits": 197, + "xEventGroupSetBitsFromISR": 59, + "xEventGroupSync": 198, + "xEventGroupWaitBits": 195, + "xQueueAddToSet": 184, + "xQueueAltGenericReceive": 172, + "xQueueAltGenericSend": 171, + "xQueueCRReceive": 176, + "xQueueCRReceiveFromISR": 174, + "xQueueCRSend": 175, + "xQueueCRSendFromISR": 173, + "xQueueCreateCountingSemaphore": 178, + "xQueueCreateMutex": 177, + "xQueueCreateSet": 183, + "xQueueGenericCreate": 47, + "xQueueGenericReceive": 49, + "xQueueGenericReset": 188, + "xQueueGenericSend": 53, + "xQueueGenericSendFromISR": 54, + "xQueueGetMutexHolder": 179, + "xQueueGiveFromISR": 61, + "xQueueGiveMutexRecursive": 181, + "xQueueIsQueueEmptyFromISR": 62, + "xQueueIsQueueFullFromISR": 63, + "xQueuePeekFromISR": 50, + "xQueueReceiveFromISR": 51, + "xQueueRemoveFromSet": 185, + "xQueueSelectFromSet": 186, + "xQueueSelectFromSetFromISR": 187, + "xQueueTakeMutexRecursive": 180, + "xTaskCallApplicationTaskHook": 143, + "xTaskCheckForTimeOut": 151, + "xTaskGenericCreate": 154, + "xTaskGenericNotify": 44, + "xTaskGenericNotifyFromISR": 45, + "xTaskGetApplicationTaskTag": 140, + "xTaskGetCurrentTaskHandle": 149, + "xTaskGetIdleTaskHandle": 144, + "xTaskGetSchedulerState": 153, + "xTaskGetTickCount": 135, + "xTaskGetTickCountFromISR": 57, + "xTaskNotifyStateClear": 148, + "xTaskNotifyWait": 46, + "xTaskPriorityDisinherit": 42, + "xTaskResumeAll": 134, + "xTaskResumeFromISR": 43, + "xTimerCreate": 158, + "xTimerCreateTimerTask": 166, + "xTimerGenericCommand": 167, + "xTimerGetTimerDaemonTaskHandle": 162, + "xTimerIsTimerActive": 161, + "xTimerPendFunctionCall": 164, + "xTimerPendFunctionCallFromISR": 163 + }, + "system": { + "SYS_IDLE": 17, + "SYS_INIT": 24, + "SYS_ISR_ENTER": 2, + "SYS_ISR_EXIT": 3, + "SYS_ISR_TO_SCHEDULER": 18, + "SYS_MODULEDESC": 24, + "SYS_NAME_RESOURCE": 25, + "SYS_NOP": 0, + "SYS_NUMMODULES": 27, + "SYS_OVERFLOW": 1, + "SYS_PRINT_FORMATTED": 26, + "SYS_STACK_INFO": 21, + "SYS_SYSDESC": 14, + "SYS_SYSTIME_CYCLES": 12, + "SYS_SYSTIME_US": 13, + "SYS_TASK_CREATE": 8, + "SYS_TASK_INFO": 9, + "SYS_TASK_START_EXEC": 4, + "SYS_TASK_START_READY": 6, + "SYS_TASK_STOP_EXEC": 5, + "SYS_TASK_STOP_READY": 7, + "SYS_TIMER_ENTER": 19, + "SYS_TIMER_EXIT": 20, + "SYS_TRACE_START": 10, + "SYS_TRACE_STOP": 11, + "SYS_USER_START": 15, + "SYS_USER_STOP": 16 + } + }, + "version": "1.0" +} diff --git a/tools/esp_app_trace/test/sysview/test.sh b/tools/esp_app_trace/test/sysview/test.sh index ec45fa09c..e1404f0b5 100755 --- a/tools/esp_app_trace/test/sysview/test.sh +++ b/tools/esp_app_trace/test/sysview/test.sh @@ -2,7 +2,15 @@ { coverage debug sys \ && coverage erase &> output \ - && coverage run -a $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -d -p cpu0.svdat cpu1.svdat test.elf &>> output \ + && coverage run -a $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -d -p -b test.elf cpu0.svdat cpu1.svdat &>> output \ && diff output expected_output \ && coverage report \ ; } || { echo 'The test for sysviewtrace_proc has failed. Please examine the artifacts.' ; exit 1; } + +{ coverage debug sys \ + && coverage erase &> output.json \ + && coverage run -a $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -j -b test.elf cpu0.svdat cpu1.svdat &>> output.json \ + && diff output.json expected_output.json \ + && coverage report \ +; } || { echo 'The test for sysviewtrace_proc JSON functionality has failed. Please examine the artifacts.' ; exit 1; } + From b81e537b7fde6fa7d6dbd1264508f354e15f7331 Mon Sep 17 00:00:00 2001 From: Alexey Gerenkov Date: Wed, 20 Nov 2019 14:47:27 +0300 Subject: [PATCH 2/2] apptrace: Extends SystemView heap & log example to run many allocator/freer tasks --- .../system/sysview_tracing_heap_log/README.md | 165 ++++++++++-------- .../main/sysview_heap_log.c | 56 ++++-- .../sdkconfig.defaults | 1 + 3 files changed, 136 insertions(+), 86 deletions(-) diff --git a/examples/system/sysview_tracing_heap_log/README.md b/examples/system/sysview_tracing_heap_log/README.md index 8e4dfad63..12caee37f 100644 --- a/examples/system/sysview_tracing_heap_log/README.md +++ b/examples/system/sysview_tracing_heap_log/README.md @@ -53,100 +53,121 @@ To run the example and collect trace data: Since SystemView tool is mostly intended for OS level analysis. It allows just to inspect custom events' timestamps and parameters. So it can require some efforts to analyse heap operations flow. IDF provides special script to make the life a bit more easy. This script parses SystemView trace file sand reports detected memory leaks. The script also prints found log messages. To run it type the following from the project root directory: ``` -$IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -p /tmp/heap_log.svdat build/sysview_tracing_heap_log.elf +$IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -p -b build/sysview_tracing_heap_log.elf /tmp/heap_log.svdat ``` Below is the sample scripts output. ``` -Parse trace from '/tmp/heap_log.svdat'... -Stop parsing trace. (Timeout 0.000000 sec while reading 1 bytes!) -Process events from '['/tmp/heap_log.svdat']'... -[0.002244575] HEAP: Allocated 1 bytes @ 0x3ffaffd8 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002272225] HEAP: Allocated 8 bytes @ 0x3ffaff6c from task "main" on core 0 by: +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:85 +/home/user/projects/esp/esp-idf/components/esp32/cpu_start.c:570 -[0.002258425] HEAP: Allocated 2 bytes @ 0x3ffaffe0 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:48 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002307300] HEAP: Allocated 2500 bytes @ 0x3ffb580c from task "main" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) -[0.002405000] LOG: I (264) example: Task[0x3ffb6cf4]: allocated 2 bytes @ 0x3ffaffe0 -[0.002553425] LOG: I (265) example: Task[0x3ffb7660]: free memory @ 0x3ffaffe0 -[0.002563725] HEAP: Freed bytes @ 0x3ffaffe0 from task "free" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:31 (discriminator 9) -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002323775] HEAP: Allocated 356 bytes @ 0x3ffb61d4 from task "main" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) -[0.002782950] HEAP: Freed bytes @ 0x3ffb40b8 from task "main" on core 0 by: -/home/user/projects/esp/esp-idf/components/freertos/tasks.c:4590 -/home/user/projects/esp/esp-idf/components/freertos/tasks.c:4590 +[0.002427700] HEAP: Allocated 120 bytes @ 0x3ffaff78 from task "alloc0" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/queue.c:391 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:46 -[0.002798700] HEAP: Freed bytes @ 0x3ffb50bc from task "main" on core 0 by: -/home/user/projects/esp/esp-idf/components/freertos/tasks.c:4590 -/home/user/projects/esp/esp-idf/components/freertos/tasks.c:4590 +[0.002471225] HEAP: Allocated 2500 bytes @ 0x3ffb633c from task "alloc0" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 -[0.102436025] HEAP: Allocated 2 bytes @ 0x3ffaffe0 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002487725] HEAP: Allocated 356 bytes @ 0x3ffb6d04 from task "alloc0" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 -[0.102449800] HEAP: Allocated 4 bytes @ 0x3ffaffe8 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:48 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002569725] HEAP: Allocated 2 bytes @ 0x3ffafff4 from task "alloc0" on core 0 by: +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:59 +/home/user/projects/esp/esp-idf/components/freertos/port.c:145 -[0.102536400] LOG: I (365) example: Task[0x3ffb6cf4]: allocated 4 bytes @ 0x3ffaffe8 -[0.102655625] LOG: I (365) example: Task[0x3ffb7660]: free memory @ 0x3ffaffe8 -[0.102666150] HEAP: Freed bytes @ 0x3ffaffe8 from task "free" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:31 (discriminator 9) -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002835275] LOG: I (298) example: Task[0x3ffb61d4]: allocated 2 bytes @ 0x3ffafff4 +[0.002974600] LOG: I (299) example: Task[0x3ffb6d04]: free memory @ 0x3ffafff4 -[0.202436200] HEAP: Allocated 3 bytes @ 0x3ffaffe8 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +.... -[0.202451725] HEAP: Allocated 6 bytes @ 0x3ffafff0 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:48 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[2.942891550] LOG: I (3239) example: Task[0x3ffb7840]: allocated 396 bytes @ 0x3ffb9d08 +[2.943024150] LOG: I (3239) example: Task[0x3ffb6d04]: free memory @ 0x3ffb9c3c +[2.943035600] HEAP: Freed bytes @ 0x3ffb9c3c from task "free0" on core 0 by: +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:24 (discriminator 9) +/home/user/projects/esp/esp-idf/components/freertos/port.c:145 -[0.202538225] LOG: I (465) example: Task[0x3ffb6cf4]: allocated 6 bytes @ 0x3ffafff0 -[0.202654475] LOG: I (465) example: Task[0x3ffb7660]: free memory @ 0x3ffafff0 -[0.202667075] HEAP: Freed bytes @ 0x3ffafff0 from task "free" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:31 (discriminator 9) -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[2.943212125] LOG: I (3239) example: Task[0x3ffb83ec]: free memory @ 0x3ffb9d08 +[2.943223500] HEAP: Freed bytes @ 0x3ffb9d08 from task "free1" on core 0 by: +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:24 (discriminator 9) +/home/user/projects/esp/esp-idf/components/freertos/port.c:145 -[0.302436000] HEAP: Allocated 4 bytes @ 0x3ffafff0 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[2.943649025] HEAP: Allocated 594 bytes @ 0x3ffb9c3c from task "alloc2" on core 0 by: +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:59 +/home/user/projects/esp/esp-idf/components/freertos/port.c:145 -[0.302451475] HEAP: Allocated 8 bytes @ 0x3ffb40b8 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:48 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[2.943734250] LOG: I (3240) example: Task[0x3ffb8f28]: allocated 594 bytes @ 0x3ffb9c3c +[2.943867850] LOG: I (3240) example: Task[0x3ffb9ad4]: free memory @ 0x3ffb9c3c +[2.943879200] HEAP: Freed bytes @ 0x3ffb9c3c from task "free2" on core 0 by: +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:24 (discriminator 9) +/home/user/projects/esp/esp-idf/components/freertos/port.c:145 -[0.302540900] LOG: I (565) example: Task[0x3ffb6cf4]: allocated 8 bytes @ 0x3ffb40b8 -[0.302657050] LOG: I (565) example: Task[0x3ffb7660]: free memory @ 0x3ffb40b8 -[0.302667500] HEAP: Freed bytes @ 0x3ffb40b8 from task "free" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:31 (discriminator 9) -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) - -Processing completed. -Processed 1027 events +[2.972813425] LOG: I (3269) example: Got notify val 2 +[2.972870400] LOG: I (3269) example: Wait notify 1 +[2.972932800] LOG: I (3269) example: Got notify val 1 +[2.972989825] LOG: I (3269) example: Wait notify 2 +[2.973756125] LOG: I (3270) example: Got notify val 1 +Processed 13467 events =============== LOG TRACE REPORT =============== -Processed 8 log messages. +Processed 600 log messages. =============== HEAP TRACE REPORT =============== -Processed 14 heap events. -[0.002244575] HEAP: Allocated 1 bytes @ 0x3ffaffd8 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +Processed 612 heap events. +[0.002272225] HEAP: Allocated 8 bytes @ 0x3ffaff6c from task "main" on core 0 by: +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:85 +/home/user/projects/esp/esp-idf/components/esp32/cpu_start.c:570 -[0.102436025] HEAP: Allocated 2 bytes @ 0x3ffaffe0 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002307300] HEAP: Allocated 2500 bytes @ 0x3ffb580c from task "main" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) -[0.202436200] HEAP: Allocated 3 bytes @ 0x3ffaffe8 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002323775] HEAP: Allocated 356 bytes @ 0x3ffb61d4 from task "main" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) -[0.302436000] HEAP: Allocated 4 bytes @ 0x3ffafff0 from task "alloc" on core 0 by: -/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 -/home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) +[0.002427700] HEAP: Allocated 120 bytes @ 0x3ffaff78 from task "alloc0" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/queue.c:391 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:46 -Found 10 leaked bytes in 4 blocks. +[0.002471225] HEAP: Allocated 2500 bytes @ 0x3ffb633c from task "alloc0" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 + +[0.002487725] HEAP: Allocated 356 bytes @ 0x3ffb6d04 from task "alloc0" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 + +[0.003102175] HEAP: Allocated 8 bytes @ 0x3ffb6e6c from task "main" on core 0 by: +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:85 +/home/user/projects/esp/esp-idf/components/esp32/cpu_start.c:570 + +.... + +[0.003713175] HEAP: Allocated 356 bytes @ 0x3ffb8f28 from task "main" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) + +[0.003814375] HEAP: Allocated 120 bytes @ 0x3ffb9090 from task "alloc2" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/queue.c:391 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:46 + +[0.003845875] HEAP: Allocated 2500 bytes @ 0x3ffb910c from task "alloc2" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 + +[0.003862350] HEAP: Allocated 356 bytes @ 0x3ffb9ad4 from task "alloc2" on core 0 by: +/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 +/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 + +Found 17520 leaked bytes in 18 blocks. ``` diff --git a/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c b/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c index 9d38fcf70..6136ca63c 100644 --- a/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c +++ b/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c @@ -32,17 +32,28 @@ static void free_task(void *p) } } +struct alloc_args { + int idx; + TaskHandle_t waiter; +}; + // allocates memory and puts addresses to the queue static void alloc_task(void *p) { - QueueHandle_t queue = (QueueHandle_t)p; + struct alloc_args *task_args = (struct alloc_args *)p; + char task_name[20]; - xTaskCreatePinnedToCore(free_task, "free", 2048, queue, 5, NULL, portNUM_PROCESSORS-1); + QueueHandle_t queue = xQueueCreate(10, sizeof(void *)); + if(queue == 0) { + ESP_LOGE(TAG, "Failed to create queue!"); + return; + } + snprintf(task_name, sizeof(task_name), "free%d", task_args->idx); + xTaskCreatePinnedToCore(free_task, task_name, 2500, queue, 5, NULL, portNUM_PROCESSORS-1); // here GDB will stop at brekpoint and execute OpenOCD command to start tracing - heap_trace_start(HEAP_TRACE_ALL); - for(int i = 1; i < 5; i++) { - uint32_t sz = 2*i; + for(int i = 1; i < 100; i++) { + uint32_t sz = 2*i*(task_args->idx + 1); void *p = malloc(sz/2); // WARNING: the previous allocated memory is intentionally not deallocated in order to cause memory leak! p = malloc(sz); @@ -50,26 +61,43 @@ static void alloc_task(void *p) if (xQueueSend(queue, ( void * )&p, portMAX_DELAY) != pdPASS) { ESP_LOGE(TAG, "Failed to send to queue!"); } + vTaskDelay(30/portTICK_PERIOD_MS); + } + xTaskNotifyGive(task_args->waiter); + while(1){ vTaskDelay(100/portTICK_PERIOD_MS); } - // here GDB will stop at brekpoint and execute OpenOCD command to stop tracing - heap_trace_stop(); - while(1); } void app_main(void) { + const int num_allocers = 3; + char task_name[20]; // redirect log messages to the host using SystemView tracing module esp_log_set_vprintf(&esp_sysview_vprintf); - QueueHandle_t queue = xQueueCreate(10, sizeof(void *)); - if(queue == 0) { - ESP_LOGE(TAG, "Failed to create queue!"); - return; - } // init host-based heap tracing if(heap_trace_init_tohost() != ESP_OK) { ESP_LOGE(TAG, "Failed to init heap trace!"); return; } - xTaskCreatePinnedToCore(alloc_task, "alloc", 2048, queue, 5, NULL, 0); + heap_trace_start(HEAP_TRACE_ALL); + for (int i = 0; i < num_allocers; i++) { + struct alloc_args *task_args = malloc(sizeof(struct alloc_args)); + if (task_args == NULL) { + ESP_LOGE(TAG, "Failed to alloc task args!"); + heap_trace_stop(); + return; + } + task_args->idx = i; + task_args->waiter = xTaskGetCurrentTaskHandle(); + snprintf(task_name, sizeof(task_name), "alloc%d", i); + xTaskCreatePinnedToCore(alloc_task, task_name, 2500, task_args, 5, NULL, 0); + } + for (int i = 0; i < num_allocers; i++) { + ESP_LOGI(TAG, "Wait notify %d", i); + uint32_t val = ulTaskNotifyTake(pdFALSE, portMAX_DELAY); + ESP_LOGI(TAG, "Got notify val %d", val); + } + // here GDB will stop at brekpoint and execute OpenOCD command to stop tracing + heap_trace_stop(); } diff --git a/examples/system/sysview_tracing_heap_log/sdkconfig.defaults b/examples/system/sysview_tracing_heap_log/sdkconfig.defaults index 0ef92e19d..3bec94224 100644 --- a/examples/system/sysview_tracing_heap_log/sdkconfig.defaults +++ b/examples/system/sysview_tracing_heap_log/sdkconfig.defaults @@ -26,3 +26,4 @@ CONFIG_SYSVIEW_EVT_TIMER_EXIT_ENABLE=y CONFIG_LOG_COLORS=n # Enable heap tracing to host CONFIG_HEAP_TRACING_TOHOST=y +CONFIG_HEAP_TRACING_STACK_DEPTH=10 \ No newline at end of file