[Enhancement] Improvements for debounce test coverage + bug fixes for sym_defer_g and sym_eager_pr

[andrebrait]

Description

• Add tests for none
• Add check for consistency between cooked_changed and actual result
• Add check for ensuring debounce never reads the timer more than once
• Fix sym_eager_pr incorrectly returning cooked_changed as false
• Fix sym_defer_g reading the timer twice when debouncing
• Save some useless memory copies on none when there are no changes
• Restructure sym_defer_g so it is smaller on AVR

Types of Changes

• Core
• Bugfix
• New feature
• Enhancement/optimization
• Keyboard (addition or update)
• Keymap/layout/userspace (addition or update)
• Documentation

Issues Fixed or Closed by This PR

Checklist

• My code follows the code style of this project: C, Python
• I have read the PR Checklist document and have made the appropriate changes.
• My change requires a change to the documentation.
• I have updated the documentation accordingly.
• I have read the CONTRIBUTING document.
• I have added tests to cover my changes.
• I have tested the changes and verified that they work and don't break anything (as well as I can manage).

[lesshonor]

This should definitely target develop.

[andrebrait]

@lesshonor thanks. Brainfart. I rebased and changed the target branch.

[andrebrait]

Ok, everything is done now. Tests have been added, too.

There was one big omission from the tests in that they didn't check if the boolean returned from debounce actually matched when the output had not changed. When it returned false, the check for the equality with the output was skipped. Now it will ensure both scenarios are consistent. With that added, I managed to confirm the bug in sym_eager_pr (it would return false even when it had changed the cooked matrix, thus breaking the test) and fixed it in this PR as well.

I made a test for reproducing an async tick and, sure enough, sym_global_g broke. It's also fixed in the PR.

@filterpaper I managed to get the size down to 16768 bytes.

With some other changes, I can manage to get to 16752, by applying the patch below. Let me know if you think it's worth it. I honestly think this is even better, but I want your opinion on it.

diff --git a/platforms/avr/timer.c b/platforms/avr/timer.c
index 65b2db1343..ca89b3dc59 100644
--- a/platforms/avr/timer.c
+++ b/platforms/avr/timer.c
@@ -83,13 +83,7 @@ inline void timer_clear(void) {
  * FIXME: needs doc
  */
 inline uint16_t timer_read(void) {
-    uint32_t t;
-
-    ATOMIC_BLOCK(ATOMIC_RESTORESTATE) {
-        t = timer_count;
-    }
-
-    return (uint16_t)t;
+    return (uint16_t)timer_read32();
 }

 /** \brief timer read32
@@ -111,27 +105,16 @@ inline uint32_t timer_read32(void) {
  * FIXME: needs doc
  */
 inline uint16_t timer_elapsed(uint16_t last) {
-    uint32_t t;
-
-    ATOMIC_BLOCK(ATOMIC_RESTORESTATE) {
-        t = timer_count;
-    }
-
-    return TIMER_DIFF_16((uint16_t)t, last);
+    return TIMER_DIFF_16(timer_read(), last);
 }

 /** \brief timer elapsed32
  *
+
  * FIXME: needs doc
  */
 inline uint32_t timer_elapsed32(uint32_t last) {
-    uint32_t t;
-
-    ATOMIC_BLOCK(ATOMIC_RESTORESTATE) {
-        t = timer_count;
-    }
-
-    return TIMER_DIFF_32(t, last);
+    return TIMER_DIFF_32(timer_read32(), last);
 }

[andrebrait]

With some other changes, I can manage to get to 16752, by applying the patch below. Let me know if you think it's worth it. I honestly think this is even better, but I want your opinion on it.

@filterpaper I went ahead and applied this patch. I can't see any downsides, with everything inlined.

[andrebrait]

Ok, so, after digging a little bit further into the subject, I see a source of problems here.

It seems that, for AVR, we get the time from the usual means, using ISRs and getting the interrupt from the CPU and using a prescaler to get the interrupt to represent 1ms. This means, @Nebuleon and @filterpaper, that I think it's also possible to get a jump of 1ms between subsequent invocations of a timer read inside the same call to debounce, even on AVR.

And due to integer division, we have a timing problem, because the current checks are basically (in all algorithms) timer_elapsed >= DEBOUNCE, and that >= will possibly be true anywhere starting from DEBOUNCE - 1 + (1 clock cycle above the prescaler), not at DEBOUNCE milliseconds or greater.

As an example (frequency of 16MHz and prescaler of 64, getting us 1 interrupt every 1ms, or 1 interrupt every 250 CPU cycles, and a DEBOUNCE of 5).

1. During debounce, we check (and store) the timer at clock 10 * 250 + 230 getting (for example) a value of 10.
2. On another matrix scan, during debounce, we read the timer at exactly 15 * 250 + 10 clock cycles, meaning we get 15 as return.
3. We consider 15 >= 10 + 5, and send the matrix update.
4. The total debouncing time was thus 4.001875ms (4 * 250 + 30 cycles), not 5

We finished debouncing at less than 5 ms here. Currently, our approach only guarantees the debounce will happen at >= DEBOUNCE -1 time.

So we have two choices here:

1. Move the checks back to >
2. Let go of the timer being in ms and count in either us or ns, and bit-shift the value gotten from the interrupts if necessary, and then the check becomes more precise since we'll have the actual time. 32-bit should be enough for the purposes of debouncing, so even in ns precision we're talking about 4 seconds before it rolls over.

@drashna not sure if this needs to involve other teams or something. Tagging you because you usually look at my PRs 😜

[Nebuleon]

I've tested these changes to none, sym_defer_g and sym_eager_pr on my keyboard while playing a Touhou MIDI file (notoriously full of notes) to induce extra interrupts taking 1-3 ms every 7.8 ms at DEBOUNCE values of 1 and 5, as well as disabling my per-key RGB to increase the matrix scan rate, and the changes work at least as well as the original code.

I've also looked at the new AsyncTickOneKeyShort1 test and the changes it required to the test harness, and they look good.

In order to make the tests you introduce in this PR pass for sym_defer_g, you had to make some changes to it, and those are also good. The changes to sym_eager_pr to make sure cooked_changed is updated based on the correct cooked row, i.e. before the update, are good and needed as well.

The only thing that remains is the matter of sym_defer_g being a bit larger on AVR. But, since it is now only calling the timer function once, which is more correct in the face of interrupts updating the timer, it's not a concern for me if this happens to be a few bytes larger.

[andrebrait]

The only thing that remains is the matter of sym_defer_g being a bit larger on AVR. But, since it is now only calling the timer function once, which is more correct in the face of interrupts updating the timer, it's not a concern for me if this happens to be a few bytes larger.

@Nebuleon not anymore. It's now smaller than in develop. @filterpaper these are the latest results.

• develop:

a_dux:
 * The firmware size is fine - 19996/28672 (69%, 8676 bytes free)

cradio:
 * The firmware size is fine - 19974/28672 (69%, 8698 bytes free)

• this PR:

a_dux: 
 * The firmware size is fine - 19988/28672 (69%, 8684 bytes free)

cradio:
 * The firmware size is fine - 19966/28672 (69%, 8706 bytes free)

[Nebuleon]

All OK for me. The change to warn on overflow of #define DEBOUNCE instead of clamping in all implementations can go in another PR, which would conflict with this one so it must be done after this one is merged.

[andrebrait]

Any chance we can get this merged? @drashna @sigprof @filterpaper

I think it was reduced enough and tested enough to be proven benign. I have a couple other improvements/cleanups on the way but those depend on this being on develop at least.