Debouncing not working - wrong clock used

[Matthijs Kooijman]

This is really an upstream bug, but I found no upstream bug tracker or contact address, so I'm hoping the upstream maintainer might be reading along here (and it's a bug in the Ubuntu version as well, so not entirely off here).

The problem is that when I set a debounce time on an input pin (with a button attached), that debounce time is not actually applied. If I set a 0.5s timeout, input events are registered immediately (and a lot of them in succession if I press the button a lot of times), instead of only reporting changes when the pin has been stable for 0.5s.

To reproduce, I have used the attached program (monitor.c), which is exactly the "monitor GPIO" example from http://abyz.me.uk/lg/examples.html#C%20lgpio with the following line added:

            lgGpioSetDebounce(h, g, 500000);

This line sets a bounce time of 500,000 μs (or 0.5 second).

When I compile and run it, and press a button attached to gpio 7 a few times quickly, I get:

$ gcc -Wall -o monitor monitor.c -llgpio
$ ./monitor 7
chip=0 gpio=7
chip=0 gpio=7 level=1 time=116.935984428
chip=0 gpio=7 level=0 time=122.184483056
chip=0 gpio=7 level=1 time=122.311010973
chip=0 gpio=7 level=0 time=122.385752598
chip=0 gpio=7 level=1 time=122.495776931
chip=0 gpio=7 level=0 time=122.536279723
chip=0 gpio=7 level=1 time=122.634267723
^C

Note that the timestamps are a lot less than 500ms apart, which should not be possible if the debouncing was working.

I investigated more closely, using the most recent version (downloaded from http://abyz.me.uk/lg/lg.zip a few days ago, I think it's 0.2.0.0) with some debug output added. I found that:
 - When an event occurs, the timestamp passed by the gpio event is used: https://salsa.debian.org/python-team/packages/lg-gpio/-/blob/upstream/0.2.0.0/lgPthAlerts.c#L488. This timestamp is by default based on CLOCK_MONOTONIC (as documented at https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/include/uapi/linux/gpio.h?h=v5.17#n283).
 - When no event occurs (for 1ms, I think), the `xNowTimestamp` is used. This is returned by `lguTimestamp()` and uses CLOCK_REALTIME (https://salsa.debian.org/python-team/packages/lg-gpio/-/blob/upstream/0.2.0.0/lgUtil.c#L46)
 - I noticed that both timestamps are really not comparable. IIRC one had about twice as many digits as the other (so I guess one of them is walltime and the other might be time since boot or something). I checked the code and both should be correctly in nanosecond precisions.
 - The xDebWatEvt compares these two timestamps to decide about bouncing. Since the now timestamp is always bigger than the event timestamps, this effectively disables the debouncing.
 - If I change `lguTimestamp()` to use CLOCK_MONOTONIC, debouncing works as expected, so all of the code seems to be correct otherwise.

I'm not sure if changing `lguTimestamp()` is the right fix here, since it might be used elsewhere that does need CLOCK_REALTIME (I haven't checked closely).

The gpio docs (https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/include/uapi/linux/gpio.h#n273) say:

 * By default the @timestamp_ns is read from %CLOCK_MONOTONIC and is
 * intended to allow the accurate measurement of the time between events.
 * It does not provide the wall-clock time.
 *
 * If the %GPIO_V2_LINE_FLAG_EVENT_CLOCK_REALTIME flag is set then the
 * @timestamp_ns is read from %CLOCK_REALTIME.

So maybe another fix is to always set the GPIO_V2_LINE_FLAG_EVENT_CLOCK_REALTIME. It seems there is some commented out to set this flag (based on, I think, user-supplied flags) already: https://salsa.debian.org/python-team/packages/lg-gpio/-/blob/upstream/0.2.0.0/lgGpio.c#L244-245

Assuming that debouncing has been tested to work when this code was originally written, I wonder if the default gpio clock was changed at some point, the clock used by lgTimestamp was changed, or maybe this was originally tested on hardware where both clocks are identical? I would dig in a bit deeper, but lacking a version control repo and also changelogs AFAICS, I'm going to just leave this here.

I've been testing this on an Orange Pi PC board, running a Ubuntu Jammy-based Armbian image.

[Matthijs Kooijman (matthijskooijman)]

I've found the upstream git repo and resubmitted this report there: https://github.com/joan2937/lg/issues/18

[Dave Jones (waveform)]

Thanks for the comprehensive report, and for taking it upstream! I'll keep an eye on it but unfortunately we're only a week away from beta freeze so I can't promise any fixes would make their way into lunar (and my plate's overflowing with breakage elsewhere!).

Still, a fix can always be SRU'd later; I'm guessing you're on jammy or kinetic given you mentioned downloading 0.2.0.0 from the source site?

[Matthijs Kooijman (matthijskooijman)]

> Thanks for the comprehensive report, and for taking it upstream! I'll keep an eye on it but unfortunately we're only a week away from beta freeze so I can't promise any fixes would make their way into lunar (and my plate's overflowing with breakage elsewhere!).
>
> Still, a fix can always be SRU'd later;

Yeah, I guess it's been like this forever (upstream suggested in a comment that it might have never worked), so no hurry. Maybe good to look at how upstream will fix it and then consider backporting that fix later.

> Still, a fix can always be SRU'd later; I'm guessing you're on jammy or kinetic given you mentioned downloading 0.2.0.0 from the source site?

Yeah, Armbian stable releases are still based on Jammy.