kinetis: timer_set_absolute randomly misses its target

[jnohlgard]

Description

Using the test application introduced in #8531, it was discovered that the implementation of timer_set_absolute sometimes misses its target when using the LPTMR hardware timer. The error seem timing dependent and occurs randomly while running the test.

Steps to reproduce the issue

Build the test application in #8531 with

CFLAGS='-DTIM_TEST_DEV=TIMER_DEV\(2\) -DTIM_TEST_FREQ=32768' make -j9 BOARD=mulle flash

Expected results

All absolute min, max, mean values < 100, variance < 100

Actual results

2018-02-07 16:48:13,928 - INFO # === timer_set_absolute ===
2018-02-07 16:48:13,931 - INFO # interval   count       sum       sum_sq    min   max  mean  variance
2018-02-07 16:48:13,935 - INFO #       1:    3046    145117      6914339     47    48    47     60
2018-02-07 16:48:13,944 - INFO #       2:    3090    145823      6882181     46    48    47     18
2018-02-07 16:48:13,947 - INFO #       3:    3037    145032      6926590     47    49    47     71
2018-02-07 16:48:13,950 - INFO #       4:    2955    139639      6599227     46    48    47     24
2018-02-07 16:48:13,960 - INFO #       5:    3050    174270    833852828     47 28756    57 270233  <=== SIC!
2018-02-07 16:48:13,961 - INFO #       6:    3017    142338      6715790     46    48    47     16
2018-02-07 16:48:13,976 - INFO #       7:    3008    115115    802297129 -28204    48    38 265365  <=== SIC!
2018-02-07 16:48:13,976 - INFO #       8:    3040    143426      6767262     46    48    47     17
2018-02-07 16:48:13,977 - INFO #       9:    3017    173481    887463109     47 29675    57 291001  <=== SIC!
2018-02-07 16:48:13,992 - INFO #      10:    3023    138443   1251241713 -30107 13464    45 412018  <=== SIC!
2018-02-07 16:48:13,993 - INFO #      11:    3092    147462      7033344     47    49    47     65
2018-02-07 16:48:13,993 - INFO #      12:    3010    142046      6703862     46    48    47     18
2018-02-07 16:48:14,009 - INFO #      13:    2994    142771      6808789     47    49    47     65
2018-02-07 16:48:14,012 - INFO #      14:    3072    144944      6839284     46    48    47     17
2018-02-07 16:48:14,024 - INFO #      15:    3122    148867      7099137     47    49    47     64
2018-02-07 16:48:14,027 - INFO #      16:    3038    146240     15615240     46  2976    48   2836  <=== SIC!
2018-02-07 16:48:14,031 - INFO #      17:    2978    142013      6772875     47    49    47     65
2018-02-07 16:48:14,041 - INFO #      18:    3067    166728    493778432     46 22067    54 158132  <=== SIC!

Versions

   arm-none-eabi-gcc: arm-none-eabi-gcc (Gentoo 7.2.0-r1 p1.1) 7.2.0
arm-none-eabi-newlib: "2.5.0"

RIOT repo: same branch as in #8531

[kaspar030]

2018-02-07 16:48:13,931 - INFO # interval count sum sum_sq min max mean variance

2018-02-07 16:48:14,041 - INFO # 18: 3067 166728 493778432 46 22067

How do I read a line like this? A timer with interval "18" was set 3067 times", ...?

[jnohlgard]

@kaspar030

2018-02-07 16:48:13,931 - INFO # interval   count       sum       sum_sq    min   max  mean  variance
2018-02-07 16:48:14,041 - INFO #      18:    3067    166728    493778432     46 22067    54 158132  <=== SIC!

Yes, read it as: The benchmark application has measured 3067 individual timer_set_absolute calls with the target (now + 18), of which the minimum measured callback time occurred at (target + 46) (an overshoot by 46 µs), the maximum measured callback time occurred at (target + 22067) (an overshoot by 22067 µs), and the mean was estimated at 54 µs overshoot. The variance is not very interesting in this case because the maximum is so large, and should be fixed first before trying to fine-tune.

[kaspar030]

LPTMR is running at 32kHZ, and being measured with an us timer (TIMER_DEV(2))?