Measuring execution time with timing.h

[ALAV]

Hi, there i want to measure code execution time of a function. I came across https://docs.zephyrproject.org/latest/reference/timing_functions/index.html. I have enabled CONFIG_TIMING_FUNCTIONS on my prj.conf file. However the build cannot link to the timing functions. I get undefined references to both board_timing functions and soc_timing functions. How can i fix this. Additionally is there a better way to measure code execution time ?

[ALAV]

Yes, I have included timing.h, when i use the borad, soc timing function i still get an undefined reference error.


Here's my proj.conf

# Enable CPP support

CONFIG_CPLUSPLUS=y

#include std c/c++, do not remove else standard design patterns will not work

CONFIG_NEWLIB_LIBC=y

CONFIG_LIB_CPLUSPLUS=y

# Enable mcumgr.

CONFIG_MCUMGR=y

# Some command handlers require a large stack.

CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=2048

# Ensure an MCUboot-compatible binary is generated.

CONFIG_BOOTLOADER_MCUBOOT=y

# Enable flash operations.

CONFIG_FLASH=y

# Required by the `taskstat` command.

CONFIG_THREAD_MONITOR=y

# Enable statistics and statistic names.

CONFIG_STATS=y

CONFIG_STATS_NAMES=y

# Enable most core commands.

CONFIG_MCUMGR_CMD_IMG_MGMT=y

CONFIG_MCUMGR_CMD_OS_MGMT=y

CONFIG_MCUMGR_CMD_STAT_MGMT=y

# Enable logging

CONFIG_LOG=y

CONFIG_MCUBOOT_UTIL_LOG_LEVEL_WRN=y

# Enable PrintK

CONFIG_PRINTK=y

CONFIG_SERIAL=y

CONFIG_UART_1_NRF_HW_ASYNC=y

CONFIG_TIMING_FUNCTIONS=y

The local includes on main.cpp

#include "wrappers/GNSS/GNSS.hpp"

#include <timing/timing.h>

and in main.cpp

    timing_t start_time, end_time;
    uint64_t total_cycles;
    uint64_t total_ns;

    soc_timing_init();
    soc_timing_start();

    start_time = soc_timing_counter_get();

    uart_read();

    end_time = soc_timing_counter_get();

    total_cycles = soc_timing_cycles_get(&start_time, &end_time);
    total_ns = soc_timing_cycles_to_ns(total_cycles);

    soc_timing_stop();

Error that i get

FAILED: zephyr/zephyr_prebuilt.elf zephyr/zephyr_prebuilt.map /home/alav/Desktop/mcumgr/build/zephyr/zephyr_prebuilt.map
: && ccache /home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/arm-zephyr-eabi-g++ zephyr/CMakeFiles/zephyr_prebuilt.dir/misc/empty_file.c.obj -o zephyr/zephyr_prebuilt.elf zephyr/CMakeFiles/offsets.dir/./arch/arm/core/offsets/offsets.c.obj -fuse-ld=bfd -Wl,-T zephyr/linker_zephyr_prebuilt.cmd -Wl,-Map=/home/alav/Desktop/mcumgr/build/zephyr/zephyr_prebuilt.map -Wl,--whole-archive app/libapp.a zephyr/libzephyr.a zephyr/arch/common/libarch__common.a zephyr/arch/arch/arm/core/aarch32/libarch__arm__core__aarch32.a zephyr/arch/arch/arm/core/aarch32/cortex_m/libarch__arm__core__aarch32__cortex_m.a zephyr/arch/arch/arm/core/aarch32/cortex_m/cmse/libarch__arm__core__aarch32__cortex_m__cmse.a zephyr/arch/arch/arm/core/aarch32/mpu/libarch__arm__core__aarch32__mpu.a zephyr/lib/libc/newlib/liblib__libc__newlib.a zephyr/lib/posix/liblib__posix.a zephyr/soc/arm/common/cortex_m/libsoc__arm__common__cortex_m.a zephyr/subsys/mgmt/mcumgr/libsubsys__mgmt__mcumgr.a zephyr/subsys/dfu/boot/libsubsys__dfu__boot.a zephyr/subsys/net/libsubsys__net.a zephyr/subsys/timing/libsubsys__timing.a zephyr/drivers/gpio/libdrivers__gpio.a zephyr/drivers/flash/libdrivers__flash.a zephyr/drivers/serial/libdrivers__serial.a modules/nrf/lib/fatal_error/lib..__nrf__lib__fatal_error.a modules/nrf/drivers/hw_cc310/lib..__nrf__drivers__hw_cc310.a modules/mcuboot/boot/bootutil/zephyr/libmcuboot_util.a modules/hal_nordic/nrfx/libmodules__hal_nordic__nrfx.a modules/mcumgr/lib..__modules__lib__mcumgr.a modules/tinycbor/lib..__modules__lib__tinycbor__zephyr.a -Wl,--no-whole-archive zephyr/kernel/libkernel.a -L"/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/10.3.0/thumb/v8-m.main/nofp" -L/home/alav/Desktop/mcumgr/build/zephyr -lgcc zephyr/arch/common/libisr_tables.a /home/alav/EmbeddedTools/ncs/nrfxlib/crypto/nrf_cc312_platform/lib/cortex-m33/soft-float/no-interrupts/libnrf_cc312_platform_0.9.11.a -mcpu=cortex-m33 -mthumb -mabi=aapcs -Wl,--gc-sections -Wl,--build-id=none -Wl,--sort-common=descending -Wl,--sort-section=alignment -Wl,-u,_OffsetAbsSyms -Wl,-u,_ConfigAbsSyms -nostdlib -static -no-pie -Wl,-X -Wl,-N -Wl,--orphan-handling=warn -lstdc++ -lm -Wl,-lc -L"/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/arm-zephyr-eabi"/lib/thumb/v8-m.main/nofp -Wl,-lgcc -lc -specs=nano.specs && cd /home/alav/Desktop/mcumgr/build/zephyr && /usr/bin/cmake -E echo
/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/10.3.0/../../../../arm-zephyr-eabi/bin/ld.bfd: app/libapp.a(main.cpp.obj): in function `main':
/home/alav/Desktop/mcumgr/smp_svr/src/main.cpp:159: undefined reference to `soc_timing_init()'
/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/10.3.0/../../../../arm-zephyr-eabi/bin/ld.bfd: /home/alav/Desktop/mcumgr/smp_svr/src/main.cpp:160: undefined reference to `soc_timing_start()'
/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/10.3.0/../../../../arm-zephyr-eabi/bin/ld.bfd: /home/alav/Desktop/mcumgr/smp_svr/src/main.cpp:162: undefined reference to `soc_timing_counter_get()'
/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/10.3.0/../../../../arm-zephyr-eabi/bin/ld.bfd: /home/alav/Desktop/mcumgr/smp_svr/src/main.cpp:174: undefined reference to `soc_timing_counter_get()'
/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/10.3.0/../../../../arm-zephyr-eabi/bin/ld.bfd: /home/alav/Desktop/mcumgr/smp_svr/src/main.cpp:176: undefined reference to `soc_timing_cycles_get(unsigned long long volatile*, unsigned long long volatile*)'
/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/10.3.0/../../../../arm-zephyr-eabi/bin/ld.bfd: /home/alav/Desktop/mcumgr/smp_svr/src/main.cpp:177: undefined reference to `soc_timing_cycles_to_ns(unsigned long long)'
/home/alav/zephyr-sdk-0.13.1/arm-zephyr-eabi/bin/../lib/gcc/arm-zephyr-eabi/10.3.0/../../../../arm-zephyr-eabi/bin/ld.bfd: /home/alav/Desktop/mcumgr/smp_svr/src/main.cpp:179: undefined reference to `soc_timing_stop()'
collect2: error: ld returned 1 exit status
ninja: build stopped: subcommand failed.

[haakonsh]

This is strange, I don't see anything terribly wrong, though you might want to enable the Floating Point Unit. 

I suggest you try to build the hello_world sample as C++ with the timing library. If it works then we have a base line build that we can compare your application to.