zephyrproject-rtos / zephyr

Primary Git Repository for the Zephyr Project. Zephyr is a new generation, scalable, optimized, secure RTOS for multiple hardware architectures.
https://docs.zephyrproject.org
Apache License 2.0
10.92k stars 6.65k forks source link

kernel: timer: timer_behavior: kernel.timer.timer fails #80823

Open katgiadla opened 2 weeks ago

katgiadla commented 2 weeks ago

Describe the bug The test tests/kernel/timer/timer_behavior/kernel.timer.timer fails.

Observed for nrf54l15dk/nrf54l15/cpuapp

To Reproduce Steps for reproducing:

  1. have nrf54l15dk/nrf54l15/cpuapp connected
  2. go to your zephyr dir
  3. call ./scripts/twister -T tests/kernel/timer/timer_behavior/ -p nrf54l15dk/nrf54l15/cpuapp --device-testing --device-serial /dev/ttyACM1 -v --inline-logs --west-flash="--erase"
  4. See console output with error

Expected behavior Valid console output

Impact Not clear

Logs and console output

===================================================================
START - test_one_tick_timer_train
Initializing 4 Timers, Tick Rate 31250Hz, Expecting 78125 callbacks in 11000 ms
Starting Timers with Skews
Faking busy work, remaining timers is 4, timer callbacks 1
Faking busy work, remaining timers is 4, timer callbacks 6414
Faking busy work, remaining timers is 4, timer callbacks 12829
Faking busy work, remaining timers is 4, timer callbacks 19247
Faking busy work, remaining timers is 4, timer callbacks 25668
Faking busy work, remaining timers is 4, timer callbacks 32088
Faking busy work, remaining timers is 4, timer callbacks 38506
Faking busy work, remaining timers is 4, timer callbacks 44927
Faking busy work, remaining timers is 4, timer callbacks 51347
Faking busy work, remaining timers is 4, timer callbacks 57765
Faking busy work, remaining timers is 4, timer callbacks 64186
Faking busy work, remaining timers is 4, timer callbacks 70610
Faking busy work, remaining timers is 4, timer callbacks 77031
One Tick Timer Train Done, took 10208 ms, busy loop ran 13 times
    Perfect delta 128 cycles or 128 us
Timer 0 max delta 139 cycles or 139 us, 0 late callbacks (0.0%)
RECORD: {"testcase":"one_tick_timer_train", "timer":0, "max_delta_cycles":139, "max_delta_us":139, "late_callbacks":0, "perfect_delta_cycles":128, "perfect_delta_us":128, "train_time_ms":10208, "busy_loops":13, "timers":4, "expected_callbacks":78125, "expected_time_ms":11000, "CONFIG_SYS_CLOCK_TICKS_PER_SEC":31250}
Timer 1 max delta 129 cycles or 129 us, 0 late callbacks (0.0%)
RECORD: {"testcase":"one_tick_timer_train", "timer":1, "max_delta_cycles":129, "max_delta_us":129, "late_callbacks":0, "perfect_delta_cycles":128, "perfect_delta_us":128, "train_time_ms":10208, "busy_loops":13, "timers":4, "expected_callbacks":78125, "expected_time_ms":11000, "CONFIG_SYS_CLOCK_TICKS_PER_SEC":31250}
Timer 2 max delta 129 cycles or 129 us, 0 late callbacks (0.0%)
RECORD: {"testcase":"one_tick_timer_train", "timer":2, "max_delta_cycles":129, "max_delta_us":129, "late_callbacks":0, "perfect_delta_cycles":128, "perfect_delta_us":128, "train_time_ms":10208, "busy_loops":13, "timers":4, "expected_callbacks":78125, "expected_time_ms":11000, "CONFIG_SYS_CLOCK_TICKS_PER_SEC":31250}
Timer 3 max delta 129 cycles or 129 us, 0 late callbacks (0.0%)
RECORD: {"testcase":"one_tick_timer_train", "timer":3, "max_delta_cycles":129, "max_delta_us":129, "late_callbacks":0, "perfect_delta_cycles":128, "perfect_delta_us":128, "train_time_ms":10208, "busy_loops":13, "timers":4, "expected_callbacks":78125, "expected_time_ms":11000, "CONFIG_SYS_CLOCK_TICKS_PER_SEC":31250}
!! The busy loop didn't run as much as expected.
!! Consider making CONFIG_SYS_CLOCK_TICKS_PER_SEC smaller.

    Assertion failed at zephyr/tests/kernel/timer/timer_behavior/src/tick_timer_train.c:180: timer_tick_train_test_one_tick_timer_train: (busy_loops > acceptable_busy_loops is false)
Expected thread to run while 1 tick timers are firing
 FAIL - test_one_tick_timer_train in 10.393 seconds
===================================================================

Environment (please complete the following information):

nordic-piks commented 2 weeks ago

Triaged internally