Button press duration can be wildly wrong due to missed ISR events (timing bug)

[KarlEffinger]

Problem

For some reason the "button released" events get fired even though the button has not been touched at all (HW-040 with additional 10k pull up and a 100nF between the button pin and GND). Only "release"-events are erroneously fired, not "pressed", so there is no "matching pair" of "pressed -> released".
When the button release event is detected, the reported duration can be bogusly large (sometimes millions of ms).
This is because buttonPressedTime is only updated on the press, and the release ISR just subtracts from whatever value is there. If the press edge is not registered (due to hardware bounce, missed interrupt, etc) or correctly does not exist, the next release yields a calculation based on outdated data, causing complete nonsense for the button duration.

Example Output

[...]
17:09:52.160 -> [  2106][D][ESP32RotaryEncoder.cpp:67] setEncoderType(): [ESP32RotaryEncoder] Encoder type set to 1
17:09:52.160 -> [  2115][D][ESP32RotaryEncoder.cpp:88] setMinValue(): [ESP32RotaryEncoder] minValue = 20
17:09:52.192 -> [  2123][D][ESP32RotaryEncoder.cpp:99] setMaxValue(): [ESP32RotaryEncoder] maxValue = 60
17:09:52.192 -> [  2131][D][ESP32RotaryEncoder.cpp:110] setCircular(): [ESP32RotaryEncoder] Boundaries are not circular
17:09:52.192 -> [  2140][D][ESP32RotaryEncoder.cpp:325] constrainValue(): [ESP32RotaryEncoder] Encoder value '0' constrained to '20'
17:09:52.224 -> [  2171][D][ESP32RotaryEncoder.cpp:187] attachInterrupts(): [ESP32RotaryEncoder] Interrupts attached
17:09:52.262 -> [  2180][D][ESP32RotaryEncoder.cpp:227] begin(): [ESP32RotaryEncoder] RotaryEncoder active
17:09:52.262 -> [  2188][D][ESP32RotaryEncoder.cpp:333] setEncoderValue(): [ESP32RotaryEncoder] Overriding encoder value from '20' to '39'
17:11:19.696 -> [ 89642][D][ESP32RotaryEncoder.cpp:369] _button_ISR(): [ESP32RotaryEncoder] Button pressed at 89642
17:11:19.877 -> [ 89835][D][ESP32RotaryEncoder.cpp:376] _button_ISR(): [ESP32RotaryEncoder] Button released at 89835
17:11:19.941 -> [ 89880][D][ESP32RotaryEncoder.cpp:269] buttonPressed(): [ESP32RotaryEncoder] Button pressed for 193 ms
17:11:29.986 -> [ 99908][D][ESP32RotaryEncoder.cpp:369] _button_ISR(): [ESP32RotaryEncoder] Button pressed at 99908
17:11:30.178 -> [100127][D][ESP32RotaryEncoder.cpp:376] _button_ISR(): [ESP32RotaryEncoder] Button released at 100127
17:11:30.245 -> [100180][D][ESP32RotaryEncoder.cpp:269] buttonPressed(): [ESP32RotaryEncoder] Button pressed for 219 ms
17:11:30.245 -> [100189][D][ESP32RotaryEncoder.cpp:88] setMinValue(): [ESP32RotaryEncoder] minValue = 20
17:11:30.245 -> [100199][D][ESP32RotaryEncoder.cpp:99] setMaxValue(): [ESP32RotaryEncoder] maxValue = 60
17:11:30.281 -> [100207][D][ESP32RotaryEncoder.cpp:110] setCircular(): [ESP32RotaryEncoder] Boundaries are not circular
17:11:30.281 -> [100216][D][ESP32RotaryEncoder.cpp:333] setEncoderValue(): [ESP32RotaryEncoder] Overriding encoder value from '240' to '39'
18:32:31.954 -> [4962008][D][ESP32RotaryEncoder.cpp:376] _button_ISR(): [ESP32RotaryEncoder] Button released at 4962008
18:32:32.053 -> [4962080][D][ESP32RotaryEncoder.cpp:269] buttonPressed(): [ESP32RotaryEncoder] Button pressed for 4862100 ms
19:04:42.333 -> [6892411][D][ESP32RotaryEncoder.cpp:376] _button_ISR(): [ESP32RotaryEncoder] Button released at 6892411
19:04:42.415 -> [6892480][D][ESP32RotaryEncoder.cpp:269] buttonPressed(): [ESP32RotaryEncoder] Button pressed for 6792503 ms
19:14:52.477 -> [7502555][D][ESP32RotaryEncoder.cpp:376] _button_ISR(): [ESP32RotaryEncoder] Button released at 7502555
19:14:52.477 -> [7502580][D][ESP32RotaryEncoder.cpp:269] buttonPressed(): [ESP32RotaryEncoder] Button pressed for 7402647 ms
19:25:02.597 -> [8112717][D][ESP32RotaryEncoder.cpp:376] _button_ISR(): [ESP32RotaryEncoder] Button released at 8112717
19:25:02.662 -> [8112780][D][ESP32RotaryEncoder.cpp:269] buttonPressed(): [ESP32RotaryEncoder] Button pressed for 8012809 ms

The gap between release events is by factors shorter than the reported durations.
The "reasonable" press duration values in the log are derived from real button presses. After 17:11:30 the rotary has not been touched.

Root cause for wrong duration calculation

See src/ESP32RotaryEncoder.cpp:

void ARDUINO_ISR_ATTR RotaryEncoder::_button_ISR() {
  // ...
  bool isPressed = !digitalRead( buttonPin );
  if( isPressed ) {
    buttonPressedTime = millis();
  } else {
    unsigned long now = millis();
    buttonPressedDuration = now - buttonPressedTime;
    buttonPressedFlag = true;
  }
  // ...
}

This logic assumes every release matches a prior press. If not, the calculation is invalid. But as can be seen on the log, there is not always a "button pressed at ..." before the "button released at..." log entries.

Why there are "button released" events detected without touching the rotary (and without button pressed events) is beyond my imagination.

Discovered using version: 1.2.0