tests/kernel/timer/timer_api failing on several nRF5x SoCs #21082

ioannisg · 2019-11-29T13:09:24Z

Describe the bug
tests/kernel/timer/timer_api fails on several nRF SoCs and Dev Kits

nrf5340_dk_nrf5340_cpuapp
nrf52833_pca10100
~~nrf52810_pca10040 (on the original 52810 HW)~~
~~nrf52811_pca10056 (on the original 52811 HW)~~

To Reproduce
Execute tests/kernel/timer/timer_api for the platforms listed above

Expected behavior
The test should pass

Impact
Concerns about the validity of the RTC timer driver implementation

Screenshots or console output

DEVICE: *** Booting Zephyr OS build v2.1.0-rc2-19-g105e0997f299  ***
DEVICE: Running test suite timer_api
DEVICE: ===================================================================
-- runners.nrfjprog: Board with serial number 960177424 flashed successfully.
DEVICE: starting test - test_time_conversions
DEVICE: PASS - test_time_conversions
DEVICE: ===================================================================
DEVICE: starting test - test_timer_duration_period
DEVICE: PASS - test_timer_duration_period
DEVICE: ===================================================================
DEVICE: starting test - test_timer_period_0
DEVICE: PASS - test_timer_period_0
DEVICE: ===================================================================
DEVICE: starting test - test_timer_expirefn_null
DEVICE: PASS - test_timer_expirefn_null
DEVICE: ===================================================================
DEVICE: starting test - test_timer_periodicity
DEVICE: PASS - test_timer_periodicity
DEVICE: ===================================================================
DEVICE: starting test - test_timer_status_get
DEVICE: PASS - test_timer_status_get
DEVICE: ===================================================================
DEVICE: starting test - test_timer_status_get_anytime
DEVICE: 
DEVICE:     Assertion failed at ZEPHYR_BASE/tests/kernel/timer/timer_api/src/main.c:335: test_timer_status_get_anytime: k_timer_status_get(&status_anytime_timer) == 4 is false
DEVICE: 
DEVICE: FAIL - test_timer_status_get_anytime
DEVICE: ===================================================================
DEVICE: starting test - test_timer_status_sync
DEVICE: PASS - test_timer_status_sync
DEVICE: ===================================================================
DEVICE: starting test - test_timer_k_define
DEVICE: PASS - test_timer_k_define
DEVICE: ===================================================================
DEVICE: starting test - test_timer_user_data
DEVICE: PASS - test_timer_user_data
DEVICE: ===================================================================
DEVICE: starting test - test_timer_remaining_get
DEVICE: PASS - test_timer_remaining_get
DEVICE: ===================================================================
DEVICE: Test suite timer_api failed.
DEVICE: ===================================================================
DEVICE: PROJECT EXECUTION FAILED
1/1 nrf5340_dk_nrf5340_cpuapp tests/kernel/timer/timer_api/kernel.timer          FAILED N/A (device 9.513s)

Environment (please complete the following information):

OS: Linux
Toolchain : Zephyr SDK
SHA: 105e099

The text was updated successfully, but these errors were encountered:

ioannisg · 2019-11-29T13:10:42Z

@kl-cruz @nika-nordic please, let me know if you can reproduce this

ioannisg · 2019-11-29T13:11:59Z

FYI @anangl @pabigot

pabigot · 2019-11-29T13:33:47Z

My test for accuracy of k_busy_wait shows that invocation on nrf5340_dk_nrf5340_cpuapp delays for twice the requested time.

req	meas
1	3.25
2	5
5	11.25
10	21.25
15	31.25
20	41.5
50	101.8
50	100.2
50	101.8
75	152.2
75	152
75	152
100	202.5
100	202.5
100	202.7
1000000	2.014 (s)

I don't have the other boards to inspect. Check the HAL implementation of nrfx_coredep_delay_us on those platforms.

kl-cruz · 2019-11-29T13:44:10Z

@pabigot could you add executing of this function right before test? It will work only for nRF5340_cpuapp.

#include <hal/nrf_cache.h>
...
nrf_cache_enable(NRF_CACHE);

ref: https://github.com/NordicSemiconductor/nrfx/blob/master/hal/nrf_cache.h#L60

anangl · 2019-11-29T13:44:46Z

@ioannisg
Regarding these two:

nrf52810_pca10040 (on the original 52810 HW)

nrf52811_pca10056 (on the original 52811 HW)

This is expected, as definitions of these boards are adjusted to give accurate delays on nRF52832 and nRF52840, respectively. See CMakeLists.txt for nrf52810_pca10040 and nrf52811_pca10056.

pabigot · 2019-11-29T13:51:07Z

nrf_cache_enable(NRF_CACHE);

@kl-cruz This doesn't seem to have any effect.

pabigot · 2019-11-29T13:52:28Z

Perhaps it's a wait state configuration issue?

ioannisg · 2019-11-29T15:32:08Z

@ioannisg
Regarding these two:

nrf52810_pca10040 (on the original 52810 HW)

nrf52811_pca10056 (on the original 52811 HW)

This is expected, as definitions of these boards are adjusted to give accurate delays on nRF52832 and nRF52840, respectively. See CMakeLists.txt for nrf52810_pca10040 and nrf52811_pca10056.

@anangl agreed, you 're right on this. I'll update the bug report description

pabigot · 2019-12-17T12:13:51Z

Is anything happening with this? I'm changing this to medium, and it should probably be high. @carlescufi

u32_t t0 = k_cycle_get_32();
k_busy_wait(1000000);
u32_t dt = k_cycle_get_32() - t0;
printk("1M us is %u ticks = %u us\n", dt, k_cyc_to_us_floor32(dt));

produces 1M us is 66080 ticks = 2016601 us on nrf5340_dk_nrf5340_cpuapp.

carlescufi · 2019-12-17T12:16:09Z

@ioannisg, @anangl and @kl-cruz can you please follow-up on this one? I am raising the priority to high because as @pabigot mentioned, this is a critical issue for nRF ICs.

nika-nordic · 2019-12-17T13:41:18Z

I've just check this for nrf52833_pca10100 on master (SHA: 9128200) and tests pass just fine.

*** Booting Zephyr OS build zephyr-v2.1.0-347-g9128200e6cf3  ***
Running test suite timer_api
===================================================================
starting test - test_time_conversions
PASS - test_time_conversions
===================================================================
starting test - test_timer_duration_period
PASS - test_timer_duration_period
===================================================================
starting test - test_timer_period_0
PASS - test_timer_period_0
===================================================================
starting test - test_timer_expirefn_null
PASS - test_timer_expirefn_null
===================================================================
starting test - test_timer_periodicity
PASS - test_timer_periodicity
===================================================================
starting test - test_timer_status_get
PASS - test_timer_status_get
===================================================================
starting test - test_timer_status_get_anytime
PASS - test_timer_status_get_anytime
===================================================================
starting test - test_timer_status_sync
PASS - test_timer_status_sync
===================================================================
starting test - test_timer_k_define
PASS - test_timer_k_define
===================================================================
starting test - test_timer_user_data
PASS - test_timer_user_data
===================================================================
starting test - test_timer_remaining_get
PASS - test_timer_remaining_get
===================================================================
Test suite timer_api succeeded
===================================================================
PROJECT EXECUTION SUCCESSFUL

When it comes to nRF53, in fact one test fails and we are investigating it.

ioannisg · 2019-12-17T13:52:15Z

@nika-nordic : assuming that you have reproduced the failure on the original SHA For pca10100; can you identify the change that has made the test pass in current master? I wonder if this test is simply fragile and depending on code paths may be either passing or failing, or if some patch has really fixed it for nrf52833.

anangl · 2019-12-17T16:40:11Z

Regarding nrf5340_dk_nrf5340_cpuapp, as @nika-nordic found during debugging the issue, the problem is in incorrect initialization of the SystemCoreClock variable. The core starts with HFCLK128M divided by 2. And the call to SystemCoreClockUpdate that is done at the end of SystemInit sets this variable properly to 64000000. However, the static initialization of the variable, performed after SystemInit, sets this variable incorrectly to 128000000.
A temporary workaround for this issue, until the MDK code is corrected, may be to call SystemCoreClockUpdate at a later stage of the system initialization, for instance in nordicsemi_nrf53_init.

nika-nordic · 2019-12-18T07:45:35Z

@ioannisg In fact I were not able to reproduce the issue on the original SHA 105e099 for nrf52833. I was using SHA: 64f3473 for hal_nordic (commit which introduces nrf52833_pca10100 to the Zephyr). This is what I get when I run the test locally on nrf52833_pca10100:

*** Booting Zephyr OS build v2.1.0-rc2-19-g105e0997f299  ***
Running test suite timer_api
===================================================================
starting test - test_time_conversions
PASS - test_time_conversions
===================================================================
starting test - test_timer_duration_period
PASS - test_timer_duration_period
===================================================================
starting test - test_timer_period_0
PASS - test_timer_period_0
===================================================================
starting test - test_timer_expirefn_null
PASS - test_timer_expirefn_null
===================================================================
starting test - test_timer_periodicity
PASS - test_timer_periodicity
===================================================================
starting test - test_timer_status_get
PASS - test_timer_status_get
===================================================================
starting test - test_timer_status_get_anytime
PASS - test_timer_status_get_anytime
===================================================================
starting test - test_timer_status_sync
PASS - test_timer_status_sync
===================================================================
starting test - test_timer_k_define
PASS - test_timer_k_define
===================================================================
starting test - test_timer_user_data
PASS - test_timer_user_data
===================================================================
starting test - test_timer_remaining_get
PASS - test_timer_remaining_get
===================================================================
Test suite timer_api succeeded
===================================================================
PROJECT EXECUTION SUCCESSFUL

nika-nordic · 2019-12-18T07:49:50Z

Thank you @anangl for detailed description. To show that this SystemCoreClockUpdate() really helps in case of nRF53, just add the call to this function inside main of tests/kernel/timer/timer_api/src/main.c:

void test_main(void)
{
        SystemCoreClockUpdate();

	timer_init(&duration_timer, duration_expire, duration_stop);
	timer_init(&period0_timer, period0_expire, NULL);
(...)

ioannisg added bug The issue is a bug, or the PR is fixing a bug platform: nRF Nordic nRFx labels Nov 29, 2019

ioannisg assigned kl-cruz and nika-nordic Nov 29, 2019

dleach02 added the priority: low Low impact/importance bug label Dec 3, 2019

pabigot added priority: medium Medium impact/importance bug and removed priority: low Low impact/importance bug labels Dec 17, 2019

carlescufi assigned ioannisg and anangl and unassigned kl-cruz and nika-nordic Dec 17, 2019

carlescufi added priority: high High impact/importance bug and removed priority: medium Medium impact/importance bug labels Dec 17, 2019

carlescufi assigned kl-cruz Dec 17, 2019

anangl mentioned this issue Dec 23, 2019

soc: nrf5340: Fix busy waiting on nRF5340 application core #21573

Merged

ioannisg closed this as completed in #21573 Jan 3, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

tests/kernel/timer/timer_api failing on several nRF5x SoCs #21082

tests/kernel/timer/timer_api failing on several nRF5x SoCs #21082

ioannisg commented Nov 29, 2019 •

edited

Loading

ioannisg commented Nov 29, 2019

ioannisg commented Nov 29, 2019

pabigot commented Nov 29, 2019

kl-cruz commented Nov 29, 2019

anangl commented Nov 29, 2019

pabigot commented Nov 29, 2019

pabigot commented Nov 29, 2019

ioannisg commented Nov 29, 2019

pabigot commented Dec 17, 2019 •

edited

Loading

carlescufi commented Dec 17, 2019 •

edited

Loading

nika-nordic commented Dec 17, 2019

ioannisg commented Dec 17, 2019

anangl commented Dec 17, 2019

nika-nordic commented Dec 18, 2019 •

edited

Loading

nika-nordic commented Dec 18, 2019

tests/kernel/timer/timer_api failing on several nRF5x SoCs #21082

tests/kernel/timer/timer_api failing on several nRF5x SoCs #21082

Comments

ioannisg commented Nov 29, 2019 • edited Loading

ioannisg commented Nov 29, 2019

ioannisg commented Nov 29, 2019

pabigot commented Nov 29, 2019

kl-cruz commented Nov 29, 2019

anangl commented Nov 29, 2019

pabigot commented Nov 29, 2019

pabigot commented Nov 29, 2019

ioannisg commented Nov 29, 2019

pabigot commented Dec 17, 2019 • edited Loading

carlescufi commented Dec 17, 2019 • edited Loading

nika-nordic commented Dec 17, 2019

ioannisg commented Dec 17, 2019

anangl commented Dec 17, 2019

nika-nordic commented Dec 18, 2019 • edited Loading

nika-nordic commented Dec 18, 2019

ioannisg commented Nov 29, 2019 •

edited

Loading

pabigot commented Dec 17, 2019 •

edited

Loading

carlescufi commented Dec 17, 2019 •

edited

Loading

nika-nordic commented Dec 18, 2019 •

edited

Loading