diff --git a/arch/riscv/core/CMakeLists.txt b/arch/riscv/core/CMakeLists.txt index 74d520458ad20..72bdee174d1e9 100644 --- a/arch/riscv/core/CMakeLists.txt +++ b/arch/riscv/core/CMakeLists.txt @@ -27,3 +27,4 @@ zephyr_library_sources_ifdef(CONFIG_USERSPACE userspace.S) zephyr_library_sources_ifdef(CONFIG_SEMIHOST semihost.c) zephyr_library_sources_ifdef(CONFIG_EXCEPTION_STACK_TRACE stacktrace.c) zephyr_linker_sources(ROM_START SORT_KEY 0x0vectors vector_table.ld) +zephyr_library_sources_ifdef(CONFIG_PROFILING_PERF perf.c) diff --git a/arch/riscv/core/perf.c b/arch/riscv/core/perf.c new file mode 100644 index 0000000000000..43de474eb6f93 --- /dev/null +++ b/arch/riscv/core/perf.c @@ -0,0 +1,93 @@ +/* + * Copyright (c) 2023 KNS Group LLC (YADRO) + * + * SPDX-License-Identifier: Apache-2.0 + */ + +#include + +static bool valid_stack(uintptr_t addr, k_tid_t current) +{ + return current->stack_info.start <= addr && + addr < current->stack_info.start + current->stack_info.size; +} + +/* + * This function use frame pointers to unwind stack and get trace of return addresses. + * Return addresses are translated in corresponding function's names using .elf file. + * So we get function call trace + */ +size_t arch_perf_current_stack_trace(uintptr_t *buf, size_t size) +{ + if (size < 2U) + return 0; + + size_t idx = 0; + + /* + * In riscv (arch/riscv/core/isr.S) ra, ip($mepc) and fp($s0) are saved + * at the beginning of _isr_wrapper in order, specified by z_arch_esf_t. + * Then, before calling interruption handler, core switch $sp to + * _current_cpu->irq_stack and save $sp with offset -16 on irq stack + * + * The following lines lines do the reverse things to get ra, ip anf fp + * from thread stack + */ + const struct arch_esf * const esf = + *((struct arch_esf **)(((uintptr_t)_current_cpu->irq_stack) - 16)); + + /* + * $s0 is used as frame pointer. + * + * stack frame in memory (commonly): + * (addresses growth up) + * .... + * [-] <- $fp($s0) (curr) + * $ra + * $fp($s0) (next) + * .... + * + * If function do not call any other function, compiller may not save $ra, + * then stack frame will be: + * .... + * [-] <- $fp($s0) (curr) + * $fp($s0) (next) + * .... + * + */ + void **fp = (void **)esf->s0; + void **new_fp = (void **)fp[-1]; + + buf[idx++] = (uintptr_t)esf->mepc; + + /* + * During function prologue and epilogue fp is equal to fp of + * previous function stack frame, it looks like second function + * from top is missed. + * So saving $ra will help in case when irq occurred in + * function prologue or epilogue. + */ + buf[idx++] = (uintptr_t)esf->ra; + if (valid_stack((uintptr_t)new_fp, _current)) { + fp = new_fp; + } + while (valid_stack((uintptr_t)fp, _current)) { + if (idx >= size) + return 0; + + buf[idx++] = (uintptr_t)fp[-1]; + new_fp = (void **)fp[-2]; + + /* + * anti-infinity-loop if + * new_fp can't be smaller than fp, cause the stack is growing down + * and trace moves deeper into the stack + */ + if (new_fp <= fp) { + break; + } + fp = new_fp; + } + + return idx; +} diff --git a/arch/x86/core/ia32.cmake b/arch/x86/core/ia32.cmake index 48207011b5009..64617f56b39f4 100644 --- a/arch/x86/core/ia32.cmake +++ b/arch/x86/core/ia32.cmake @@ -25,6 +25,8 @@ zephyr_library_sources_ifdef(CONFIG_GDBSTUB ia32/gdbstub.c) zephyr_library_sources_ifdef(CONFIG_DEBUG_COREDUMP ia32/coredump.c) +zephyr_library_sources_ifdef(CONFIG_PROFILING_PERF ia32/perf.c) + zephyr_library_sources_ifdef( CONFIG_X86_USE_THREAD_LOCAL_STORAGE ia32/tls.c diff --git a/arch/x86/core/ia32/intstub.S b/arch/x86/core/ia32/intstub.S index 4cd5c0bee9040..dd454670dd886 100644 --- a/arch/x86/core/ia32/intstub.S +++ b/arch/x86/core/ia32/intstub.S @@ -112,11 +112,12 @@ SECTION_FUNC(PINNED_TEXT, _interrupt_enter) * EAX = isr_param, EDX = isr */ - /* Push EDI as we will use it for scratch space. + /* Push EBP as we will use it for scratch space. + * Also it helps in stack unwinding * Rest of the callee-saved regs get saved by invocation of C * functions (isr handler, arch_swap(), etc) */ - pushl %edi + pushl %ebp /* load %ecx with &_kernel */ @@ -131,17 +132,17 @@ SECTION_FUNC(PINNED_TEXT, _interrupt_enter) jne alreadyOnIntStack /* - * switch to base of the interrupt stack: save esp in edi, then load + * switch to base of the interrupt stack: save esp in ebp, then load * irq_stack pointer */ - movl %esp, %edi + movl %esp, %ebp movl _kernel_offset_to_irq_stack(%ecx), %esp /* save thread's stack pointer onto base of interrupt stack */ - pushl %edi /* Save stack pointer */ + pushl %ebp /* Save stack pointer */ #ifdef CONFIG_PM cmpl $0, _kernel_offset_to_idle(%ecx) @@ -265,7 +266,7 @@ alreadyOnIntStack: #endif /* CONFIG_LAZY_FPU_SHARING */ /* Restore volatile registers and return to the interrupted thread */ - popl %edi + popl %ebp popl %ecx popl %edx popl %eax @@ -298,7 +299,7 @@ noReschedule: */ nestedInterrupt: - popl %edi + popl %ebp popl %ecx /* pop volatile registers in reverse order */ popl %edx popl %eax diff --git a/arch/x86/core/ia32/perf.c b/arch/x86/core/ia32/perf.c new file mode 100644 index 0000000000000..1f212317626fa --- /dev/null +++ b/arch/x86/core/ia32/perf.c @@ -0,0 +1,81 @@ +/* + * Copyright (c) 2023 KNS Group LLC (YADRO) + * Copyright (c) 2020 Yonatan Goldschmidt + * + * SPDX-License-Identifier: Apache-2.0 + */ + +#include + +static bool valid_stack(uintptr_t addr, k_tid_t current) +{ + return current->stack_info.start <= addr && + addr < current->stack_info.start + current->stack_info.size; +} + +/* interruption stack frame */ +struct isf { + uint32_t ebp; + uint32_t ecx; + uint32_t edx; + uint32_t eax; + uint32_t eip; +}; + +/* + * This function use frame pointers to unwind stack and get trace of return addresses. + * Return addresses are translated in corresponding function's names using .elf file. + * So we get function call trace + */ +size_t arch_perf_current_stack_trace(uintptr_t *buf, size_t size) +{ + if (size < 1U) + return 0; + + size_t idx = 0; + + const struct isf * const isf = + *((struct isf **)(((void **)_current_cpu->irq_stack)-1)); + /* + * In x86 (arch/x86/core/ia32/intstub.S) %eip and %ebp + * are saved at the beginning of _interrupt_enter in order, that described + * in struct esf. Core switch %esp to + * _current_cpu->irq_stack and push %esp on irq stack + * + * The following lines lines do the reverse things to get %eip and %ebp + * from thread stack + */ + void **fp = (void **)isf->ebp; + + /* + * %ebp is frame pointer. + * + * stack frame in memory: + * (addresses growth up) + * .... + * ra + * %ebp (next) <- %ebp (curr) + * .... + */ + + buf[idx++] = (uintptr_t)isf->eip; + while (valid_stack((uintptr_t)fp, _current)) { + if (idx >= size) + return 0; + + buf[idx++] = (uintptr_t)fp[1]; + void **new_fp = (void **)fp[0]; + + /* + * anti-infinity-loop if + * new_fp can't be smaller than fp, cause the stack is growing down + * and trace moves deeper into the stack + */ + if (new_fp <= fp) { + break; + } + fp = new_fp; + } + + return idx; +} diff --git a/arch/x86/core/intel64.cmake b/arch/x86/core/intel64.cmake index 1cb25ebe220e5..dd3bb38af7a09 100644 --- a/arch/x86/core/intel64.cmake +++ b/arch/x86/core/intel64.cmake @@ -20,3 +20,4 @@ zephyr_library_sources_ifdef(CONFIG_IRQ_OFFLOAD intel64/irq_offload.c) zephyr_library_sources_ifdef(CONFIG_USERSPACE intel64/userspace.S) zephyr_library_sources_ifdef(CONFIG_THREAD_LOCAL_STORAGE intel64/tls.c) zephyr_library_sources_ifdef(CONFIG_DEBUG_COREDUMP intel64/coredump.c) +zephyr_library_sources_ifdef(CONFIG_PROFILING_PERF intel64/perf.c) diff --git a/arch/x86/core/intel64/perf.c b/arch/x86/core/intel64/perf.c new file mode 100644 index 0000000000000..754450100ab5d --- /dev/null +++ b/arch/x86/core/intel64/perf.c @@ -0,0 +1,67 @@ +/* + * Copyright (c) 2023 KNS Group LLC (YADRO) + * Copyright (c) 2020 Yonatan Goldschmidt + * + * SPDX-License-Identifier: Apache-2.0 + */ + +#include + +static bool valid_stack(uintptr_t addr, k_tid_t current) +{ + return current->stack_info.start <= addr && + addr < current->stack_info.start + current->stack_info.size; +} + +/* + * This function use frame pointers to unwind stack and get trace of return addresses. + * Return addresses are translated in corresponding function's names using .elf file. + * So we get function call trace + */ +size_t arch_perf_current_stack_trace(uintptr_t *buf, size_t size) +{ + if (size < 1U) + return 0; + + size_t idx = 0; + + /* + * In x86_64 (arch/x86/core/intel64/locore.S) %rip and %rbp + * are always saved in _current->callee_saved before calling + * handler function if interrupt is not nested + * + * %rip points the location where interrupt was occurred + */ + buf[idx++] = (uintptr_t)_current->callee_saved.rip; + void **fp = (void **)_current->callee_saved.rbp; + + /* + * %rbp is frame pointer. + * + * stack frame in memory: + * (addresses growth up) + * .... + * ra + * %rbp (next) <- %rbp (curr) + * .... + */ + while (valid_stack((uintptr_t)fp, _current)) { + if (idx >= size) + return 0; + + buf[idx++] = (uintptr_t)fp[1]; + void **new_fp = (void **)fp[0]; + + /* + * anti-infinity-loop if + * new_fp can't be smaller than fp, cause the stack is growing down + * and trace moves deeper into the stack + */ + if (new_fp <= fp) { + break; + } + fp = new_fp; + } + + return idx; +} diff --git a/doc/services/index.rst b/doc/services/index.rst index b8c0534e82dab..d900f110a65af 100644 --- a/doc/services/index.rst +++ b/doc/services/index.rst @@ -28,6 +28,7 @@ OS Services pm/index.rst portability/index.rst poweroff.rst + profiling/index.rst shell/index.rst serialization/index.rst settings/index.rst diff --git a/doc/services/profiling/index.rst b/doc/services/profiling/index.rst new file mode 100644 index 0000000000000..a6040a4509bbd --- /dev/null +++ b/doc/services/profiling/index.rst @@ -0,0 +1,11 @@ +.. _profiling: + +Profiling +######### + +Required Kconfig: :kconfig:option:`CONFIG_PROFILING` + +.. toctree:: + :maxdepth: 1 + + perf.rst diff --git a/doc/services/profiling/perf.rst b/doc/services/profiling/perf.rst new file mode 100644 index 0000000000000..9d421e88f1dc9 --- /dev/null +++ b/doc/services/profiling/perf.rst @@ -0,0 +1,91 @@ +.. _profiling-perf: + + +Perf +#### + + +Perf is a profiler tool, based on stack tracing. It can be used to light weight profiling +almost without any code overhead. + +Work principe +************* + +``perf record`` shell-command starts timer with perf tracer function. +Timers are driven by inerrupts, so perf tracer function is calling during interruption. +Zephyr core save return address and frame pointer in interrupt stack or ``callee_saved`` +struture before caling interrupt hundler. So perf trace function makes stack traces by +using return address and frame pointer. + +Then stackcollapse.py script convert return addresses in stack trace to function names +by elf file and print them in required for FlameGraph format. + +Configuration +************* + +Configure this module using the following options. + +* :kconfig:option:`CONFIG_PROFILING_PERF`: enable the module. This opion add + perf command in shell. + +* :kconfig:option:`CONFIG_PROFILING_PERF_BUFFER_SIZE`: sets size of perf buffer, + where samples are saved before printing. + +Usage +***** + +More specific example can be found in :zephyr:code-sample:`profiling-perf`. + +#. Build with perf enabled and run. + +#. Begin perf sampling by shell-command + + .. code-block:: text + + perf record + + This command will start timer with perf sampler for *period* in seconds and + with *frequency* in hertz. + + Wait for the completion message ``perf done!`` or ``perf buf override!`` + (if perf buffer size is smaller than required). + +#. Print made by perf samles in terminal by shell-command + + .. code-block:: text + + perf printbuf + + Output exaple: + + .. code-block:: text + + Perf buf length 1985 + 0000000000000004 + 0000000080004e58 + 00000000800071ca + 0000000080000964 + aaaaaaaaaaaaaaaa + 0000000000000002 + .... + 00000000800163e0 + + Copy gotten output in some file, for example *perf_buf*. + +#. Translate perf samples by stackcollapse script to format, required by FlameGraph + + .. code-block:: bash + + python zephyr/scripts/perf/stackcollapse.py perf_buf /zephyr/zephyr.elf > perf_buf.folded + + And turn into .svg FlameGraph (for example *graph.svg*) + + .. code-block:: bash + + ./FlameGraph/flamegraph.pl perf_buf.folded > graph.svg + + All this step can be done by one command + + .. code-block:: bash + + python zephyr/scripts/perf/stackcollapse.py perf_buf /zephyr/zephyr.elf | ./FlameGraph/flamegraph.pl > graph.svg diff --git a/samples/subsys/profiling/perf/CMakeLists.txt b/samples/subsys/profiling/perf/CMakeLists.txt new file mode 100644 index 0000000000000..f21d25038e1dc --- /dev/null +++ b/samples/subsys/profiling/perf/CMakeLists.txt @@ -0,0 +1,10 @@ +# Copyright (c) 2023 KNS Group LLC (YADRO) +# +# SPDX-License-Identifier: Apache-2.0 + +cmake_minimum_required(VERSION 3.20.0) + +find_package(Zephyr REQUIRED HINTS $ENV{ZEPHYR_BASE}) +project(perf) + +target_sources(app PRIVATE src/main.c) diff --git a/samples/subsys/profiling/perf/README.rst b/samples/subsys/profiling/perf/README.rst new file mode 100644 index 0000000000000..124ee496615c3 --- /dev/null +++ b/samples/subsys/profiling/perf/README.rst @@ -0,0 +1,69 @@ +.. zephyr:code-sample:: profiling-perf + :name: Perf tool + + Send perf samples to the host with console support + +This application can be used to demonstrate :ref:`profiling-perf` work. + +Requirements +************ + +Perf tool so far implemente only for riscv and x86_64 architectures. + +Usage example +************* + +Build an image with: + +.. zephyr-app-commands:: + :zephyr-app: samples/subsys/profiling/perf + :board: qemu_riscv64 + :goals: build + :compact: + +After the sample starts, enter shell command: + +.. code-block:: console + + uart:~$ perf record + +Wait for the completion message ``perf done!`` or ``perf buf override!`` +(if perf buffer size is smaller than required). + +Print made by perf samles in terminal by shell-command: + +.. code-block:: console + + uart:~$ perf printbuf + +Output exaple: + +.. code-block:: console + + Perf buf length 2046 + 0000000000000004 + 00000000001056b2 + 0000000000108192 + 000000000010052f + 0000000000000000 + .... + 000000000010052f + 0000000000000000 + +Copy gotten output in some file, for example *perf_buf*. + +Make graph.svg with :zephyr_file:`scripts/perf/stackcollapse.py` and +`FlameGraph`_: + +.. _FlameGraph: https://github.com/brendangregg/FlameGraph/ + +.. code-block:: shell + + python scripts/perf/stackcollapse.py perf_buf build/zephyr/zephyr.elf | /flamegraph.pl > graph.svg + +Graph example +============= + +.. image:: images/graph_example.svg + :align: center + :alt: graph example diff --git a/samples/subsys/profiling/perf/images/graph_example.svg b/samples/subsys/profiling/perf/images/graph_example.svg new file mode 100644 index 0000000000000..19c2e8d1837ac --- /dev/null +++ b/samples/subsys/profiling/perf/images/graph_example.svg @@ -0,0 +1,521 @@ + + + + + + + + + + + + + + +Flame Graph + +Reset Zoom +Search +ic + + + +z_impl_k_busy_wait (60 samples, 23.26%) +z_impl_k_busy_wait + + +sys_clock_cycle_get_32 (40 samples, 15.50%) +sys_clock_cycle_get_32 + + +all (258 samples, 100%) + + + +sys_clock_cycle_get_32 (20 samples, 7.75%) +sys_clock_.. + + +sys_clock_cycle_get_32 (20 samples, 7.75%) +sys_clock_.. + + +z_impl_k_busy_wait (78 samples, 30.23%) +z_impl_k_busy_wait + + +sys_clock_cycle_get_32 (40 samples, 15.50%) +sys_clock_cycle_get_32 + + +z_impl_k_busy_wait (20 samples, 7.75%) +z_impl_k_b.. + + +func_0 (80 samples, 31.01%) +func_0 + + +sys_clock_cycle_get_32 (59 samples, 22.87%) +sys_clock_cycle_get_32 + + +z_impl_k_busy_wait (40 samples, 15.50%) +z_impl_k_busy_wait + + +main (218 samples, 84.50%) +main + + +func_0_1 (40 samples, 15.50%) +func_0_1 + + +idle (40 samples, 15.50%) +idle + + +func_1 (60 samples, 23.26%) +func_1 + + +arch_cpu_idle (40 samples, 15.50%) +arch_cpu_idle + + +z_thread_entry (258 samples, 100.00%) +z_thread_entry + + +bg_thread_main (218 samples, 84.50%) +bg_thread_main + + +func_0_0 (20 samples, 7.75%) +func_0_0 + + +z_impl_k_busy_wait (20 samples, 7.75%) +z_impl_k_b.. + + +func_2 (78 samples, 30.23%) +func_2 + + +[unknown] (258 samples, 100.00%) +[unknown] + + + diff --git a/samples/subsys/profiling/perf/prj.conf b/samples/subsys/profiling/perf/prj.conf new file mode 100644 index 0000000000000..e93083d3da327 --- /dev/null +++ b/samples/subsys/profiling/perf/prj.conf @@ -0,0 +1,6 @@ +CONFIG_PROFILING=y +CONFIG_PROFILING_PERF=y +CONFIG_THREAD_STACK_INFO=y +CONFIG_SMP=n +CONFIG_SHELL=y +CONFIG_FRAME_POINTER=y diff --git a/samples/subsys/profiling/perf/pytest/test_perf.py b/samples/subsys/profiling/perf/pytest/test_perf.py new file mode 100755 index 0000000000000..1bb4c6a7cb002 --- /dev/null +++ b/samples/subsys/profiling/perf/pytest/test_perf.py @@ -0,0 +1,39 @@ +#!/usr/bin/env python3 +# +# Copyright (c) 2023 KNS Group LLC (YADRO) +# +# SPDX-License-Identifier: Apache-2.0 + +import logging +import re + +from twister_harness import Shell +from twister_harness import DeviceAdapter + +logger = logging.getLogger(__name__) + + +def test_shell_perf(dut: DeviceAdapter, shell: Shell): + + shell.base_timeout=10 + + logger.info('send "perf record 200 99" command') + lines = shell.exec_command('perf record 200 99') + assert 'Enabled perf' in lines, 'expected response not found' + lines = dut.readlines_until(regex='.*Perf done!', print_output=True) + logger.info('response is valid') + + logger.info('send "perf printbuf" command') + lines = shell.exec_command('perf printbuf') + lines = lines[1:-1] + match = re.match(r"Perf buf length (\d+)", lines[0]) + assert match is not None, 'expected response not found' + length = int(match.group(1)) + lines = lines[1:] + assert length != 0, '0 length' + assert length == len(lines), 'length dose not match with count of lines' + + i = 0 + while i < length: + i += int(lines[i], 16) + 1 + assert i <= length, 'one of the samples is not true to size' diff --git a/samples/subsys/profiling/perf/sample.yaml b/samples/subsys/profiling/perf/sample.yaml new file mode 100644 index 0000000000000..261c2f957bb50 --- /dev/null +++ b/samples/subsys/profiling/perf/sample.yaml @@ -0,0 +1,18 @@ +sample: + description: Sample, that can be used for testing profiling perf tool + name: perf sample + +tests: + sample.perf: + tags: + - perf + - profiling + extra_configs: + - CONFIG_PROFILING_PERF_BUFFER_SIZE=128 + filter: CONFIG_RISCV or CONFIG_X86 + integration_platforms: + - qemu_riscv64 + - qemu_riscv32 + - qemu_x86_64 + - qemu_x86 + harness: pytest diff --git a/samples/subsys/profiling/perf/src/main.c b/samples/subsys/profiling/perf/src/main.c new file mode 100644 index 0000000000000..7576e1994ce0d --- /dev/null +++ b/samples/subsys/profiling/perf/src/main.c @@ -0,0 +1,55 @@ +/* + * Copyright (c) 2023 KNS Group LLC (YADRO) + * + * SPDX-License-Identifier: Apache-2.0 + */ + +#include +#include + +#define WAIT_KOEF 10000 + +#define NOINLINE __attribute__((noinline)) + +int NOINLINE func_0_0(void) +{ + k_busy_wait(1*WAIT_KOEF); + return 0; +} + +int NOINLINE func_0_1(void) +{ + k_busy_wait(2*WAIT_KOEF); + return 0; +} + +int NOINLINE func_0(void) +{ + k_busy_wait(1*WAIT_KOEF); + func_0_0(); + func_0_1(); + return 0; +} + +int NOINLINE func_1(void) +{ + k_busy_wait(3*WAIT_KOEF); + return 0; +} + +int NOINLINE func_2(void) +{ + k_busy_wait(4*WAIT_KOEF); + return 0; +} + +int main(void) +{ + while (1) { + k_usleep(1000); + func_0(); + func_1(); + func_2(); + } + return 0; +} diff --git a/samples/subsys/profiling/profiling.rst b/samples/subsys/profiling/profiling.rst new file mode 100644 index 0000000000000..a9765517a4b39 --- /dev/null +++ b/samples/subsys/profiling/profiling.rst @@ -0,0 +1,10 @@ +.. _profiling-samples: + +Profiling subsystem samples +########################### + +.. toctree:: + :maxdepth: 1 + :glob: + + **/* diff --git a/scripts/profiling/stackcollapse.py b/scripts/profiling/stackcollapse.py new file mode 100644 index 0000000000000..38088527fcaf8 --- /dev/null +++ b/scripts/profiling/stackcollapse.py @@ -0,0 +1,65 @@ +#!/usr/bin/env python3 +# +# Copyright (c) 2023 KNS Group LLC (YADRO) +# Copyright (c) 2020 Yonatan Goldschmidt +# +# SPDX-License-Identifier: Apache-2.0 + +""" +Stack compressor for FlameGraph + +This translate stack samples captured by perf subsystem into format +used by flamegraph.pl. Translation uses .elf file to get function names +from addresses + +Usage: + ./script/perf/stackcollapse.py +""" + +import re +import sys +import struct +import binascii +from functools import lru_cache +from elftools.elf.elffile import ELFFile + + +@lru_cache(maxsize=None) +def addr_to_sym(addr, elf): + symtab = elf.get_section_by_name(".symtab") + for sym in symtab.iter_symbols(): + if sym.entry.st_info.type == "STT_FUNC" and sym.entry.st_value <= addr < sym.entry.st_value + sym.entry.st_size: + return sym.name + if addr == 0: + return "nullptr" + return "[unknown]" + + +def collapse(buf, elf): + while buf: + count, = struct.unpack_from(">Q", buf) + assert count > 0 + addrs = struct.unpack_from(f">{count}Q", buf, 8) + + func_trace = reversed(list(map(lambda a: addr_to_sym(a, elf), addrs))) + prev_func = next(func_trace) + line = prev_func + # merge dublicate functions + for func in func_trace: + if prev_func != func: + prev_func = func + line += ";" + func + + print(line, 1) + buf = buf[8 + 8 * count:] + + +if __name__ == "__main__": + elf = ELFFile(open(sys.argv[2], "rb")) + with open(sys.argv[1], "r") as f: + inp = f.read() + + lines = inp.splitlines() + assert int(re.match(r"Perf buf length (\d+)", lines[0]).group(1)) == len(lines) - 1 + buf = binascii.unhexlify("".join(lines[1:])) + collapse(buf, elf) diff --git a/subsys/CMakeLists.txt b/subsys/CMakeLists.txt index 584559fa50e67..58f0cf6ffc3e2 100644 --- a/subsys/CMakeLists.txt +++ b/subsys/CMakeLists.txt @@ -48,6 +48,7 @@ add_subdirectory_ifdef(CONFIG_JWT jwt) add_subdirectory_ifdef(CONFIG_LLEXT llext) add_subdirectory_ifdef(CONFIG_MODEM_MODULES modem) add_subdirectory_ifdef(CONFIG_NET_BUF net) +add_subdirectory_ifdef(CONFIG_PROFILING profiling) add_subdirectory_ifdef(CONFIG_RETENTION retention) add_subdirectory_ifdef(CONFIG_SENSING sensing) add_subdirectory_ifdef(CONFIG_SETTINGS settings) diff --git a/subsys/Kconfig b/subsys/Kconfig index 2c708e26d59ec..59c7fa1721018 100644 --- a/subsys/Kconfig +++ b/subsys/Kconfig @@ -33,6 +33,7 @@ source "subsys/modem/Kconfig" source "subsys/net/Kconfig" source "subsys/pm/Kconfig" source "subsys/portability/Kconfig" +source "subsys/profiling/Kconfig" source "subsys/random/Kconfig" source "subsys/retention/Kconfig" source "subsys/rtio/Kconfig" diff --git a/subsys/profiling/CMakeLists.txt b/subsys/profiling/CMakeLists.txt new file mode 100644 index 0000000000000..223d049486c2d --- /dev/null +++ b/subsys/profiling/CMakeLists.txt @@ -0,0 +1,5 @@ +# Copyright (c) 2023 KNS Group LLC (YADRO) +# +# SPDX-License-Identifier: Apache-2.0 + +add_subdirectory_ifdef(CONFIG_PROFILING_PERF perf) diff --git a/subsys/profiling/Kconfig b/subsys/profiling/Kconfig new file mode 100644 index 0000000000000..6239b974ca35b --- /dev/null +++ b/subsys/profiling/Kconfig @@ -0,0 +1,14 @@ +# Copyright (c) 2023 KNS Group LLC (YADRO) +# +# SPDX-License-Identifier: Apache-2.0 + +menuconfig PROFILING + bool "Profiling tools" + help + Enable profiling tools, such as perf + +if PROFILING + +source "subsys/profiling/perf/Kconfig" + +endif diff --git a/subsys/profiling/perf/CMakeLists.txt b/subsys/profiling/perf/CMakeLists.txt new file mode 100644 index 0000000000000..4ab7b625d7281 --- /dev/null +++ b/subsys/profiling/perf/CMakeLists.txt @@ -0,0 +1,5 @@ +# Copyright (c) 2023 KNS Group LLC (YADRO) +# +# SPDX-License-Identifier: Apache-2.0 + +zephyr_sources(perf.c) diff --git a/subsys/profiling/perf/Kconfig b/subsys/profiling/perf/Kconfig new file mode 100644 index 0000000000000..b9d58f6f20f7d --- /dev/null +++ b/subsys/profiling/perf/Kconfig @@ -0,0 +1,23 @@ +# Copyright (c) 2023 KNS Group LLC (YADRO) +# +# SPDX-License-Identifier: Apache-2.0 + +config PROFILING_PERF + bool "Perf support" + depends on THREAD_STACK_INFO + depends on !SMP + depends on FRAME_POINTER + depends on SHELL + depends on RISCV || X86 + help + Enable perf shell command. + +if PROFILING_PERF + +config PROFILING_PERF_BUFFER_SIZE + int "Perf buffer size" + default 2048 + help + Size of buffer, that used by perf to save samples from stack tracing. + +endif diff --git a/subsys/profiling/perf/perf.c b/subsys/profiling/perf/perf.c new file mode 100644 index 0000000000000..e0c0dcba79359 --- /dev/null +++ b/subsys/profiling/perf/perf.c @@ -0,0 +1,145 @@ +/* + * Copyright (c) 2023 KNS Group LLC (YADRO) + * Copyright (c) 2020 Yonatan Goldschmidt + * + * SPDX-License-Identifier: Apache-2.0 + */ + +#include +#include +#include +#include +#include +#include +#include + +size_t arch_perf_current_stack_trace(uintptr_t *buf, size_t size); + +struct perf_data_t { + struct k_timer timer; + + const struct shell *sh; + + struct k_work_delayable dwork; + + size_t idx; + uintptr_t buf[CONFIG_PROFILING_PERF_BUFFER_SIZE]; + bool buf_full; +}; + +#define PERF_EVENT_TRACING_BUF_OVERFLOW (1 << 0) + +static struct perf_data_t perf_data = { + .idx = 0, +}; + +static void perf_tracer(struct k_timer *timer) +{ + struct perf_data_t *perf_data_ptr = + (struct perf_data_t *)k_timer_user_data_get(timer); + + size_t trace_length = 0; + + if (++perf_data_ptr->idx < CONFIG_PROFILING_PERF_BUFFER_SIZE) { + trace_length = arch_perf_current_stack_trace( + perf_data_ptr->buf + perf_data_ptr->idx, + CONFIG_PROFILING_PERF_BUFFER_SIZE - perf_data_ptr->idx); + } + + if (trace_length != 0) { + perf_data_ptr->buf[perf_data_ptr->idx - 1] = trace_length; + perf_data_ptr->idx += trace_length; + } else { + --perf_data_ptr->idx; + perf_data_ptr->buf_full = true; + k_timer_stop(timer); + k_work_reschedule(&perf_data_ptr->dwork, K_NO_WAIT); + } +} + +static void perf_dwork_handler(struct k_work *work) +{ + struct k_work_delayable *dwork = k_work_delayable_from_work(work); + struct perf_data_t *perf_data_ptr = CONTAINER_OF(dwork, struct perf_data_t, dwork); + + if (perf_data_ptr->buf_full) { + shell_error(perf_data_ptr->sh, "Perf buf overflow!"); + } else { + k_timer_stop(&perf_data_ptr->timer); + shell_print(perf_data_ptr->sh, "Perf done!"); + } +} + +static int perf_init(void) +{ + k_timer_init(&perf_data.timer, perf_tracer, NULL); + k_work_init_delayable(&perf_data.dwork, perf_dwork_handler); + + return 0; +} + +int cmd_perf_record(const struct shell *sh, size_t argc, char **argv) +{ + if (k_work_delayable_is_pending(&perf_data.dwork)) { + shell_warn(sh, "Perf is already running"); + return -EINPROGRESS; + } + + if (perf_data.buf_full) { + shell_warn(sh, "Perf buffer is full"); + return -ENOBUFS; + } + + k_timeout_t duration = K_MSEC(strtoll(argv[1], NULL, 10)); + k_timeout_t period = K_NSEC(1000000000 / strtoll(argv[2], NULL, 10)); + + perf_data.sh = sh; + + k_timer_user_data_set(&perf_data.timer, &perf_data); + k_timer_start(&perf_data.timer, K_NO_WAIT, period); + + k_work_schedule(&perf_data.dwork, duration); + + shell_print(sh, "Enabled perf"); + + return 0; +} + +int cmd_perf_print(const struct shell *sh, size_t argc, char **argv) +{ + if (k_work_delayable_is_pending(&perf_data.dwork)) { + shell_warn(sh, "Perf is already running"); + return -EINPROGRESS; + } + + shell_print(sh, "Perf buf length %zu", perf_data.idx); + for (size_t i = 0; i < perf_data.idx; i++) { + shell_print(sh, "%016lx", perf_data.buf[i]); + } + + perf_data.idx = 0; + + return 0; +} + +static int cmd_perf(const struct shell *sh, size_t argc, char **argv) +{ + ARG_UNUSED(argc); + ARG_UNUSED(argv); + + shell_print(sh, "perfy"); + return 0; +} + +#define CMD_HELP_RECORD \ + "Start recording for ms on Hz\n" \ + "Usage: record \n" + +SHELL_STATIC_SUBCMD_SET_CREATE(m_sub_perf, + SHELL_CMD_ARG(record, NULL, CMD_HELP_RECORD, cmd_perf_record, 3, 0), + SHELL_CMD_ARG(printbuf, NULL, "Print the perf buffer", cmd_perf_print, 0, 0), + SHELL_SUBCMD_SET_END +); +SHELL_CMD_ARG_REGISTER(perf, &m_sub_perf, "Perf!", cmd_perf, 0, 0); + +SYS_INIT(perf_init, APPLICATION, 0);