search

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.66k stars 6.53k forks source link

tests: kernel: timer: timer_behavior: kernel.timer.timer fails #57326

Closed katgiadla closed 1 year ago

katgiadla commented 1 year ago

Describe the bug The kernel.timer.timer fails. For board nrf5340dk_nrf5340_cpuapp fails and for rest of below, it behaves unstable.

Observed for:

To Reproduce Steps to reproduce the behavior:

  1. have nrf5340dk_nrf5340_cpuapp connected
  2. go to your zephyr dir
  3. call ./scripts/twister -T tests/kernel/timer/timer_behavior/kernel.timer.timer -p nrf5340dk_nrf5340_cpuapp --device-testing --device-serial /dev/ttyACM0 -v --inline-logs
  4. See console output with error

Expected behavior Valid console output

Impact Not clear

Logs and console output

*** Booting Zephyr OS build zephyr-v3.3.0-3164-ga0ad7b7752e6 ***
Running TESTSUITE timer_jitter_drift
===================================================================
START - test_jitter_drift_timer_period
periodic timer behavior test using built-in restart mechanism
collecting time samples for approx 10 seconds
periodic timer samples gathered, calculating statistics
timer clock rate 32768, kernel tick rate 8192
expected period drift: 98.632812 us
period duration statistics for 10000 samples (0 rollovers):
expected: 1000 us,       32.768000 cycles
min:      1098.632812 us, 36 cycles
max:      1220.703125 us, 40 cycles
mean:     1098.645020 us, 36.000400 cycles
variance: 1.489967 us, 0.001600 cycles
stddev:   1.220642 us, 0.039998 cycles
timer start cycle 9169, end cycle 369173,
total time 10986450.195312 us, expected time 10000000.000000 us,
expected time drift 986328.125000 us, difference 122.070313 us
Assertion failed at ../../../../../../../../../zephyr/zephyr/tests/kernel/timer/timer_behavior/src/jitter_drift.c:242: do_test_using: (max_us <= max_us_bound is false)
Longest timer period too long (off by more than expected 10%)
FAIL - test_jitter_drift_timer_period in 11.196 seconds
===================================================================
START - test_jitter_drift_timer_startdelay
periodic timer behavior test using explicit start with delay
collecting time samples for approx 10 seconds
periodic timer samples gathered, calculating statistics
timer clock rate 32768, kernel tick rate 8192
expected period drift: 98.632812 us
period duration statistics for 10000 samples (0 rollovers):
expected: 1000 us,       32.768000 cycles
min:      1098.632812 us, 36 cycles
max:      1098.632812 us, 36 cycles
mean:     1098.632812 us, 36.000000 cycles
variance: 0.000000 us, 0.000000 cycles
stddev:   0.000000 us, 0.000000 cycles
timer start cycle 376532, end cycle 736532,
total time 10986328.125000 us, expected time 10000000.000000 us,
expected time drift 986328.125000 us, difference 0.000000 us
PASS - test_jitter_drift_timer_startdelay in 11.134 seconds
===================================================================
TESTSUITE timer_jitter_drift failed.
Running TESTSUITE timer_tick_train
===================================================================
START - test_one_tick_timer_train
Initializing 4 Timers, Tick Rate 8192Hz, Expecting 20480 callbacks in 11000 ms
Starting Timers with Skews
Faking busy work, remaining timers is 4, timer callbacks 0
Faking busy work, remaining timers is 4, timer callbacks 689
Faking busy work, remaining timers is 4, timer callbacks 1377
Faking busy work, remaining timers is 4, timer callbacks 2066
Faking busy work, remaining timers is 4, timer callbacks 2755
Faking busy work, remaining timers is 4, timer callbacks 3444
Faking busy work, remaining timers is 4, timer callbacks 4133
Faking busy work, remaining timers is 4, timer callbacks 4822
Faking busy work, remaining timers is 4, timer callbacks 5511
Faking busy work, remaining timers is 4, timer callbacks 6200
Faking busy work, remaining timers is 4, timer callbacks 6889
Faking busy work, remaining timers is 4, timer callbacks 7578
Faking busy work, remaining timers is 4, timer callbacks 8268
Faking busy work, remaining timers is 4, timer callbacks 8957
Faking busy work, remaining timers is 4, timer callbacks 9646
Faking busy work, remaining timers is 4, timer callbacks 10335
Faking busy work, remaining timers is 4, timer callbacks 11024
Faking busy work, remaining timers is 4, timer callbacks 11713
Faking busy work, remaining timers is 4, timer callbacks 12402
Faking busy work, remaining timers is 4, timer callbacks 13092
Faking busy work, remaining timers is 4, timer callbacks 13781
Faking busy work, remaining timers is 4, timer callbacks 14470
Faking busy work, remaining timers is 4, timer callbacks 15160
Faking busy work, remaining timers is 4, timer callbacks 15849
Faking busy work, remaining timers is 4, timer callbacks 16539
Faking busy work, remaining timers is 4, timer callbacks 17228
Faking busy work, remaining timers is 4, timer callbacks 17918
Faking busy work, remaining timers is 4, timer callbacks 18607
Faking busy work, remaining timers is 4, timer callbacks 19295
Faking busy work, remaining timers is 4, timer callbacks 19981
One Tick Timer Train Done, took 10070 ms, busy loop ran 30 times
Perfect delta 16 cycles or 488 us
Timer 0 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
Timer 1 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
Timer 2 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
Timer 3 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
!! The busy loop didn't run as much as expected.
!! Consider making CONFIG_SYS_CLOCK_TICKS_PER_SEC smaller.
PASS - test_one_tick_timer_train in 10.122 seconds
===================================================================
TESTSUITE timer_tick_train succeeded
------ TESTSUITE SUMMARY START ------
SUITE FAIL -  50.00% [timer_jitter_drift]: pass = 1, fail = 1, skip = 0, total = 2 duration = 22.330 seconds
- FAIL - [timer_jitter_drift.test_jitter_drift_timer_period] duration = 11.196 seconds
- PASS - [timer_jitter_drift.test_jitter_drift_timer_startdelay] duration = 11.134 seconds
SUITE PASS - 100.00% [timer_tick_train]: pass = 1, fail = 0, skip = 0, total = 1 duration = 10.122 seconds
- PASS - [timer_tick_train.test_one_tick_timer_train] duration = 10.122 seconds
------ TESTSUITE SUMMARY END ------
===================================================================
RunID: de60ff5cd37853b5a87a7f000902655e
PROJECT EXECUTION FAILED

Environment (please complete the following information):

nordicjm commented 1 year ago

Did you run this with the DK UART workaround Kconfig disabled?

FRASTM commented 1 year ago

Similar issue found with stm32 boards : https://github.com/zephyrproject-rtos/zephyr/issues/57285 --> a possible WA was to reduce the CONFIG_SYS_CLOCK_TICKS_PER_SEC for boards with 32MHz kernel clock https://github.com/zephyrproject-rtos/zephyr/issues/57288

jgl-meta commented 1 year ago

@teburd

katgiadla commented 1 year ago

Similar problem occurred on nrf52840dk_nrf52840:

[2023-05-02T20:22:56.258Z] ERROR   - *** Booting Zephyr OS build zephyr-v3.3.0-3341-gef3d01d16fd4 ***
[2023-05-02T20:22:56.258Z] Running TESTSUITE timer_jitter_drift
[2023-05-02T20:22:56.258Z] ===================================================================
[2023-05-02T20:22:56.258Z] START - test_jitter_drift_timer_period
[2023-05-02T20:22:56.258Z] periodic timer behavior test using built-in restart mechanism
[2023-05-02T20:22:56.258Z] collecting time samples for approx 10 seconds
[2023-05-02T20:22:56.258Z] periodic timer samples gathered, calculating statistics
[2023-05-02T20:22:56.258Z] timer clock rate 32768, kernel tick rate 8192
[2023-05-02T20:22:56.258Z] expected period drift: 98.632812 us
[2023-05-02T20:22:56.258Z] period duration statistics for 10000 samples (0 rollovers):
[2023-05-02T20:22:56.258Z] expected: 1000 us,           32.768000 cycles
[2023-05-02T20:22:56.258Z] min:      1098.632812 us,    36 cycles
[2023-05-02T20:22:56.258Z] max:      1098.632812 us,    36 cycles
[2023-05-02T20:22:56.258Z] mean:     1098.632812 us,    36.000000 cycles
[2023-05-02T20:22:56.258Z] variance: 0.000000 us,   0.000000 cycles
[2023-05-02T20:22:56.258Z] stddev:   0.000000 us,   0.000000 cycles
[2023-05-02T20:22:56.258Z] timer start cycle 13701, end cycle 373701,
[2023-05-02T20:22:56.258Z] total time 10986328.125000 us, expected time 10000000.000000 us,
[2023-05-02T20:22:56.258Z] expected time drift 986328.125000 us, difference 0.000000 us
[2023-05-02T20:22:56.258Z] PASS - test_jitter_drift_timer_period in 11.135 seconds
[2023-05-02T20:22:56.258Z] ===================================================================
[2023-05-02T20:22:56.258Z] START - test_jitter_drift_timer_startdelay
[2023-05-02T20:22:56.258Z] periodic timer behavior test using explicit start with delay
[2023-05-02T20:22:56.258Z] collecting time samples for approx 10 seconds
[2023-05-02T20:22:56.258Z] periodic timer samples gathered, calculating statistics
[2023-05-02T20:22:56.258Z] timer clock rate 32768, kernel tick rate 8192
[2023-05-02T20:22:56.258Z] expected period drift: 98.632812 us
[2023-05-02T20:22:56.258Z] period duration statistics for 10000 samples (0 rollovers):
[2023-05-02T20:22:56.258Z] expected: 1000 us,           32.768000 cycles
[2023-05-02T20:22:56.258Z] min:      1098.632812 us,    36 cycles
[2023-05-02T20:22:56.259Z] max:      1220.703125 us,    40 cycles
[2023-05-02T20:22:56.259Z] mean:     1098.645020 us,    36.000400 cycles
[2023-05-02T20:22:56.259Z] variance: 1.489967 us,   0.001600 cycles
[2023-05-02T20:22:56.259Z] stddev:   1.220642 us,   0.039998 cycles
[2023-05-02T20:22:56.259Z] timer start cycle 379048, end cycle 739052,
[2023-05-02T20:22:56.259Z] total time 10986450.195312 us, expected time 10000000.000000 us,
[2023-05-02T20:22:56.259Z] expected time drift 986328.125000 us, difference 122.070313 us
[2023-05-02T20:22:56.259Z] Assertion failed at ../../../../../../../../../zephyr/zephyr/tests/kernel/timer/timer_behavior/src/jitter_drift.c:242: do_test_using: (max_us <= max_us_bound is false)
[2023-05-02T20:22:56.259Z] Longest timer period too long (off by more than expected 10%)
[2023-05-02T20:22:56.259Z] FAIL - test_jitter_drift_timer_startdelay in 11.195 seconds
[2023-05-02T20:22:56.259Z] ===================================================================
[2023-05-02T20:22:56.259Z] TESTSUITE timer_jitter_drift failed.
[2023-05-02T20:22:56.259Z] Running TESTSUITE timer_tick_train
[2023-05-02T20:22:56.259Z] ===================================================================
[2023-05-02T20:22:56.259Z] START - test_one_tick_timer_train
[2023-05-02T20:22:56.259Z] Initializing 4 Timers, Tick Rate 8192Hz, Expecting 20480 callbacks in 11000 ms
[2023-05-02T20:22:56.259Z] Starting Timers with Skews
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 0
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 645
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 1290
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 1935
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 2580
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 3225
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 3870
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 4515
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 5160
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 5805
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 6451
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 7096
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 7741
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 8386
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 9031
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 9675
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 10320
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 10965
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 11610
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 12255
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 12900
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 13545
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 14189
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 14834
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 15479
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 16124
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 16769
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 17415
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 18060
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 18704
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 19348
[2023-05-02T20:22:56.259Z] Faking busy work, remaining timers is 4, timer callbacks 19990
[2023-05-02T20:22:56.259Z] One Tick Timer Train Done, took 10060 ms, busy loop ran 32 times
[2023-05-02T20:22:56.259Z] Perfect delta 16 cycles or 488 us
[2023-05-02T20:22:56.259Z] Timer 0 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
[2023-05-02T20:22:56.259Z] Timer 1 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
[2023-05-02T20:22:56.259Z] Timer 2 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
[2023-05-02T20:22:56.259Z] Timer 3 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
[2023-05-02T20:22:56.259Z] !! The busy loop didn't run as much as expected.
[2023-05-02T20:22:56.259Z] !! Consider making CONFIG_SYS_CLOCK_TICKS_PER_SEC smaller.
[2023-05-02T20:22:56.259Z] PASS - test_one_tick_timer_train in 10.110 seconds
[2023-05-02T20:22:56.259Z] ===================================================================
[2023-05-02T20:22:56.259Z] TESTSUITE timer_tick_train succeeded
[2023-05-02T20:22:56.259Z] ------ TESTSUITE SUMMARY START ------
[2023-05-02T20:22:56.259Z] SUITE FAIL -  50.00% [timer_jitter_drift]: pass = 1, fail = 1, skip = 0, total = 2 duration = 22.330 seconds
[2023-05-02T20:22:56.259Z] - PASS - [timer_jitter_drift.test_jitter_drift_timer_period] duration = 11.135 seconds
[2023-05-02T20:22:56.259Z] - FAIL - [timer_jitter_drift.test_jitter_drift_timer_startdelay] duration = 11.195 seconds
[2023-05-02T20:22:56.259Z] SUITE PASS - 100.00% [timer_tick_train]: pass = 1, fail = 0, skip = 0, total = 1 duration = 10.110 seconds
[2023-05-02T20:22:56.259Z] - PASS - [timer_tick_train.test_one_tick_timer_train] duration = 10.110 seconds
[2023-05-02T20:22:56.259Z] ------ TESTSUITE SUMMARY END ------
[2023-05-02T20:22:56.259Z] ===================================================================
[2023-05-02T20:22:56.259Z] RunID: dc7ae3d26a811fd14ec77379f98db2da
[2023-05-02T20:22:56.259Z] PROJECT EXECUTION FAILED
[2023-05-02T20:22:56.259Z] 
katgiadla commented 1 year ago

Issue occured on nrf9160dk_nrf9160_ns:

[2023-05-05T03:17:26.868Z] ERROR   -  *** Booting Zephyr OS build v3.2.99-ncs2-5067-gb54c8baeeafb ***
[2023-05-05T03:17:26.868Z] Running TESTSUITE timer_jitter_drift
[2023-05-05T03:17:26.868Z] ===================================================================
[2023-05-05T03:17:26.868Z] START - test_jitter_drift
[2023-05-05T03:17:26.868Z] periodic timer behavior test (approx 10 seconds)
[2023-05-05T03:17:26.868Z] periodic timer samples gathered, calculating statistics
[2023-05-05T03:17:26.868Z] timer clock rate 32768, kernel tick rate 8192
[2023-05-05T03:17:26.868Z] expected period drift: 98.632812 us
[2023-05-05T03:17:26.868Z] period duration statistics for 10000 samples (0 rollovers):
[2023-05-05T03:17:26.868Z] expected: 1000 us,           32.768000 cycles
[2023-05-05T03:17:26.868Z] min:      1098.632812 us,    36 cycles
[2023-05-05T03:17:26.868Z] max:      1220.703125 us,    40 cycles
[2023-05-05T03:17:26.868Z] mean:     1098.645020 us,    36.000400 cycles
[2023-05-05T03:17:26.868Z] variance: 1.489967 us,   0.001600 cycles
[2023-05-05T03:17:26.868Z] stddev:   1.220642 us,   0.039998 cycles
[2023-05-05T03:17:26.868Z] timer start cycle 16329, end cycle 376333,
[2023-05-05T03:17:26.868Z] total time 10986450.195312 us, expected time 10000000.000000 us,
[2023-05-05T03:17:26.868Z] expected time drift 986328.125000 us, difference 122.070313 us
[2023-05-05T03:17:26.868Z] Assertion failed at ../../../../../../../../../ncs/zephyr/tests/kernel/timer/timer_behavior/src/jitter_drift.c:199: timer_jitter_drift_test_jitter_drift: (max_us <= max_us_bound is false)
[2023-05-05T03:17:26.868Z] Longest timer period too long (off by more than expected 10%)
[2023-05-05T03:17:26.868Z] FAIL - test_jitter_drift in 11.212 seconds
[2023-05-05T03:17:26.868Z] ===================================================================
[2023-05-05T03:17:26.868Z] TESTSUITE timer_jitter_drift failed.
[2023-05-05T03:17:26.868Z] Running TESTSUITE timer_tick_train
[2023-05-05T03:17:26.868Z] ===================================================================
[2023-05-05T03:17:26.868Z] START - test_one_tick_timer_train
[2023-05-05T03:17:26.868Z] Initializing 4 Timers, Tick Rate 8192Hz, Expecting 20480 callbacks in 11000 ms
[2023-05-05T03:17:26.868Z] Starting Timers with Skews
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 0
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 676
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 1352
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 2028
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 2704
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 3380
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 4056
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 4731
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 5407
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 6083
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 6759
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 7435
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 8111
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 8787
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 9463
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 10139
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 10815
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 11492
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 12168
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 12844
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 13521
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 14197
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 14873
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 15549
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 16225
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 16901
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 17577
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 18253
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 18930
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 19606
[2023-05-05T03:17:26.868Z] Faking busy work, remaining timers is 4, timer callbacks 20282
[2023-05-05T03:17:26.868Z] One Tick Timer Train Done, took 10182 ms, busy loop ran 31 times
[2023-05-05T03:17:26.868Z] Perfect delta 16 cycles or 488 us
[2023-05-05T03:17:26.868Z] Timer 0 max delta 17 cycles or 519 us, 0 late callbacks (0.0%)
[2023-05-05T03:17:26.868Z] Timer 1 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
[2023-05-05T03:17:26.868Z] Timer 2 max delta 17 cycles or 519 us, 0 late callbacks (0.0%)
[2023-05-05T03:17:26.868Z] Timer 3 max delta 16 cycles or 488 us, 0 late callbacks (0.0%)
[2023-05-05T03:17:26.868Z] !! The busy loop didn't run as much as expected.
[2023-05-05T03:17:26.868Z] !! Consider making CONFIG_SYS_CLOCK_TICKS_PER_SEC smaller.
[2023-05-05T03:17:26.868Z] PASS - test_one_tick_timer_train in 10.234 seconds
[2023-05-05T03:17:26.868Z] ===================================================================
[2023-05-05T03:17:26.868Z] TESTSUITE timer_tick_train succeeded
[2023-05-05T03:17:26.868Z] ------ TESTSUITE SUMMARY START ------
[2023-05-05T03:17:26.868Z] SUITE FAIL -   0.00% [timer_jitter_drift]: pass = 0, fail = 1, skip = 0, total = 1 duration = 11.212 seconds
[2023-05-05T03:17:26.868Z] - FAIL - [timer_jitter_drift.test_jitter_drift] duration = 11.212 seconds
[2023-05-05T03:17:26.868Z] SUITE PASS - 100.00% [timer_tick_train]: pass = 1, fail = 0, skip = 0, total = 1 duration = 10.234 seconds
[2023-05-05T03:17:26.868Z] - PASS - [timer_tick_train.test_one_tick_timer_train] duration = 10.234 seconds
[2023-05-05T03:17:26.868Z] ------ TESTSUITE SUMMARY END ------
[2023-05-05T03:17:26.868Z] ===================================================================
[2023-05-05T03:17:26.868Z] RunID: b92dfa528cdfa77343677a4b39cbcfb6
[2023-05-05T03:17:26.868Z] PROJECT EXECUTION FAILED
[2023-05-05T03:17:26.868Z]