spurious IRQs in `periph_timer`

maribu commented 1 year ago

Description

It turned out that some periph_timer implementations just masked IRQs on timer_clear(). If the interrupt condition then occurred later on, the IRQ flag was set but (due to being masked) not executed. However, the next call to timer_set_absolute() unmasked the IRQ, which resulted in the pending flag to directly cause the timer to fire.

Expected results

timer_set_absolute() doesn't fire directly on setting (if the target is in the future), so that tests/periph_timer from https://github.com/RIOT-OS/RIOT/pull/18963 passes.

Actual results

timer_set_absolute() occasionally fires right away at least on some implementations and https://github.com/RIOT-OS/RIOT/pull/18963 fails.

Tracking

[ ] ATXmega: fails the test early on and is in need of fixing
[x] ATmega: https://github.com/RIOT-OS/RIOT/pull/18978
[ ] CC2538: ?
[x] CC26xx / CC13xx: Not affected (but the test fails due to a different issue)
[x] EFM32: Not affected
[x] ESP32: Not affected
[x] ESP8266: Not affected
[x] FE310: https://github.com/RIOT-OS/RIOT/pull/19112
[ ] GD32V: ?
[ ] Kinetis: ?
[ ] LPC1768: ?
[x] LPC23xx: Not affected
[ ] MSP430: ?
[ ] Native: ?
[x] QN908x: Not affected, unrelated timer bug fixed in https://github.com/RIOT-OS/RIOT/pull/18989
[x] RP2040: Not affected
[x] SAM0: Not affected
[x] SAM3: Not affected
[x] STM32: https://github.com/RIOT-OS/RIOT/pull/18969
[x] nRF5x: https://github.com/RIOT-OS/RIOT/pull/18970

Versions

Current master, 2022.10-branch

jue89 commented 1 year ago

EFM32 Series 2 looks good for the TIMER and LPTIMER peripheral. EFM32 Series 0 and 1 have be tested separately. I don't have a board at hand.

fabian18 commented 1 year ago

RP2040 is still passing the new test, so it seems to be not affected.

2022-11-25 22:10:37,262 # Help: Press s to start test, r to print it is ready
s
2022-11-25 22:10:39,171 # START
2022-11-25 22:10:39,180 # main(): This is RIOT! (Version: 2023.01-devel-473-g496ab-tests/periph_timer)
2022-11-25 22:10:39,181 # 
2022-11-25 22:10:39,182 # Test for peripheral TIMERs
2022-11-25 22:10:39,182 # 
2022-11-25 22:10:39,183 # Available timers: 1
2022-11-25 22:10:39,183 # 
2022-11-25 22:10:39,184 # Testing TIMER_0:
2022-11-25 22:10:39,187 # TIMER_0: initialization successful
2022-11-25 22:10:39,189 # TIMER_0: stopped
2022-11-25 22:10:39,191 # TIMER_0: set channel 0 to 5000
2022-11-25 22:10:39,194 # TIMER_0: set channel 1 to 10000
2022-11-25 22:10:39,196 # TIMER_0: set channel 2 to 15000
2022-11-25 22:10:39,199 # TIMER_0: set channel 3 to 20000
2022-11-25 22:10:39,201 # TIMER_0: starting
2022-11-25 22:10:39,227 # TIMER_0: channel 0 fired at SW count    20813 - init:    20813
2022-11-25 22:10:39,232 # TIMER_0: channel 1 fired at SW count    41584 - diff:    20771
2022-11-25 22:10:39,237 # TIMER_0: channel 2 fired at SW count    62407 - diff:    20823
2022-11-25 22:10:39,243 # TIMER_0: channel 3 fired at SW count    83231 - diff:    20824
2022-11-25 22:10:39,247 # 
2022-11-25 22:10:39,248 # TEST SUCCEEDED
2022-11-25 22:10:39,257 # { "threads": [{ "name": "main", "stack_size": 1536, "stack_used": 440 }]}

maribu commented 1 year ago

SAM3 is also fine:


$ make BOARD=arduino-due flash test -C tests/periph_timer
[...]
Help: Press s to start test, r to print it is ready
READY
s
START
main(): This is RIOT! (Version: 2023.01-devel-473-g496ab-tests/periph_timer)

Test for peripheral TIMERs

Available timers: 2

Testing TIMER_0:
TIMER_0: initialization successful
TIMER_0: stopped
TIMER_0: set channel 0 to 5000
TIMER_0: starting
TIMER_0: channel 0 fired at SW count    18261 - init:    18261

Testing TIMER_1:
TIMER_1: initialization successful
TIMER_1: stopped
TIMER_1: set channel 0 to 5000
TIMER_1: starting
TIMER_1: channel 0 fired at SW count    18259 - init:    18259

TEST SUCCEEDED
``

maribu commented 1 year ago

It seems that qn908x is not affected by this bug:

Help: Press s to start test, r to print it is ready
READY
s
START
main(): This is RIOT! (Version: 2023.01-devel-473-g496ab-tests/periph_timer)

Test for peripheral TIMERs

Available timers: 4

Testing TIMER_0:
TIMER_0: initialization successful
TIMER_0: stopped
TIMER_0: set channel 0 to 5000
TIMER_0: set channel 1 to 10000
TIMER_0: set channel 2 to 15000
TIMER_0: set channel 3 to 20000
TIMER_0: starting
TIMER_0: channel 0 fired at SW count    39971 - init:    39971
TIMER_0: ERROR callback argument mismatch

Testing TIMER_1:
TIMER_1: initialization successful
TIMER_1: stopped
TIMER_1: set channel 0 to 5000
TIMER_1: set channel 1 to 10000
TIMER_1: set channel 2 to 15000
TIMER_1: set channel 3 to 20000
TIMER_1: starting
TIMER_1: channel 0 fired at SW count    39970 - init:    39970
TIMER_1: ERROR callback argument mismatch

Testing TIMER_2:
TIMER_2: initialization successful
TIMER_2: stopped
TIMER_2: set channel 0 to 5000
TIMER_2: set channel 1 to 10000
TIMER_2: set channel 2 to 15000
TIMER_2: set channel 3 to 20000
TIMER_2: starting
TIMER_2: channel 0 fired at SW count    39972 - init:    39972
TIMER_2: ERROR callback argument mismatch

Testing TIMER_3:
TIMER_3: initialization successful
TIMER_3: stopped
TIMER_3: set channel 0 to 5000
TIMER_3: set channel 1 to 10000
TIMER_3: set channel 2 to 15000
TIMER_3: set channel 3 to 20000
TIMER_3: starting
TIMER_3: channel 0 fired at SW count    39970 - init:    39970
TIMER_3: ERROR callback argument mismatch

TEST FAILED
{ "threads": [{ "name": "main", "stack_size": 1536, "stack_used": 408 }]}
Timeout in expect script at "child.expect('TEST SUCCEEDED')" (tests/periph_timer/tests/01-run.py:21)

make: *** [/home/maribu/Repos/software/RIOT/makefiles/tests/tests.inc.mk:26: test] Error 1

However, the bug it is affected by doesn't look that friendly, either.

maribu commented 1 year ago

The CC26xx/CC13xx is not affected by this bug, but 2 out of four timers do not initialize (so the test fails).

maribu commented 1 year ago

@bergzand: I'm almost sure the GD32V will be affected, as the periph_timer driver was copy-pasted from the STM32 driver at a state it was still affected. Care to take a look?

RIOT-OS / RIOT