Iot: GpioButtonWait - wrong expectations and output inside the code

[hidegh]

Describe the bug
The variable at will never be in "pressed" state, as the waitResult.EventTypes does not returns the type of the current event, but it returns the events we're listening to, so it's value is a [Flag] value: PinEventTypes.Rising | PinEventTypes.Failing see: https://github.com/dotnet/iot/blob/ae9ba984e1b637807185d648cb1c208d13f8db3e/tools/DevicesApiTester/Commands/Gpio/GpioButtonWait.cs#L76

For starters is there a HOW TO PDF?

For anyone interesting in any button event, keep this in mind:

1. pressing and releasing the button will fire both events
2. some HW might behave weird (like mine is able to fire one of the events twice if pressed in quick sequence, but the touch sensor works as expected)

A clear and concise description of what the bug is.
Just a wrong output to console, but it's a misleading stuff for starters.

Steps to reproduce
Just see the console output when pressing/releasing the button.

Expected behavior
So while the current code does behave as expected and just the output is not correct (expectations from some lines in the code are simply not fulfilled)...a proper way to check if button was just pressed can be achieved with a callback, see code below:

                    controller.RegisterCallbackForPinValueChangedEvent(
                        buttonPin,
                        inputEvents,
                        (object sender, PinValueChangedEventArgs pinValueChangedEventArgs) =>
                        {
                            Debug.WriteLine($"{DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fff")} Btn event: {pinValueChangedEventArgs.ChangeType}");

                            if (pinValueChangedEventArgs.ChangeType == PinEventTypes.Rising)
                            {
                                isOn = !isOn;
                                controller.Write(ledPin, isOn ? PinValue.High : PinValue.Low);
                            }
                        }
                        );

Actual behavior
Just wrong output and well, bad expectations (badly set pressedOrReleased variable).

Versions used
Latest 2020/01
RPI 3B+
.NET Core 3.1

[pgrawehr]

Thanks for the report, clearly this was a bug (WaitForEvent never read the new value of the pin). Added a patch to the already open PR #914.
Note that you may miss interrupts if the program is not fast enough to restart waiting.
@krwq: For the event driven approach, I think I could fix that as well (because I know the previous state), in the WaitForEvent explicit call that's harder. Do you consider this worth the effort?

[hidegh]

@pgrawehr The event driven approach was OK and working as expected. The WaitForEvent indeed can miss some events.

Actually I've checked your fixes and well, I'm a bit confused:

1. I assume the new code now correctly returns the button state at the given event
2. yet the property is called: waitResult.EventTypes and not waitResult.EventType nor waitResult.DetectedEventType

...I'm just referring to this: originally I thought that the intent with the WaitResult was not to give any feedback on the last button event, but instead just a feeedback on what types of events were listened to. see:

reg: https://github.com/pgrawehr/iot/commit/8897983f715af8a6d937aabc1492ec0bab52685a

So for your changes i'd probably suggest this:

1. store the event type in a new property, extend WaitResult
2. keep original waitResult.DetectedEventType as it was

Or if you revert those, then the sample has to be updated with a:

[pgrawehr]

Oh, sometimes, one needs to read the docs first...
I would add the extra property to WaitResult, as it simplifies the code on the user side, especially since (dependent on the abstraction layer being used) additional delays need to be introduced between getting the interrupt and reading the new value.

[joperezr]

Thanks for reporting this @hidegh. Do you mind giving more info into what driver you were using? In order to know that, we would have to know where is it that you were running (linux/windows) and then if linux, it would help to know if you were running on a Raspberry Pi, and also if you had libgpiod installed in your machine.

[hidegh]

@joperezr it's .NET Core 3 used on Raspbian stretch with Raspberry Pi 3B+; Latest IotNuget at that time.

But as mentioned it's not my code, nor a malfunction, it's a wrong sample on the repository. The sample wrongly assumes that the property EventTypes is the type which lead to the event, but as proven in the screenshot (where the desciption is from XML summary fields, so part of the IOT documentation) the property is just the events we set to listen for (see link: https://github.com/dotnet/iot/issues/925#issuecomment-570942001).

So again, no problem on my side,
Problem (bug) is in the sample code - see 1st entry, with line number attached,

Solutions:

1. keep current property as is, it's called EventTypes, and based on documentation it should contains the values we listen for (so in the case of the sample both for raising and falling edges)
2. update and fix the bug in the sample project - not because of me (i already figured it out) but because of others with less exp. working with IOT
3. and a good idea would be to extend that event with a EventType property (or call it: RaisedEvent) into which the event type that occured is set.

@pgrawehr "Oh, sometimes, one needs to read the docs first..." - Is there somewhere a comprehensing documentation?

[pgrawehr]

@joperezr I think the original behavior was really a bug that got introduced _because_ the documentation was missleading. (Remember out conversation in https://github.com/dotnet/iot/pull/914#discussion_r365097534 ?) Also since the linux and the windows version behaved differently and returning the argument in the result is not really meaningful I fixed that over in #914.

@hidegh No, unfortunately. The XML documentation and the readme's (where available) are all there is on documentation. In this particular case, the description of that member is just ambiguous, Since the implementation for different hardware is also different (some returning the desired, some returning the actual value), that's IMHO something that's really wrong in the code.

[joperezr]

Here is a bit more background info on the subject. When we were initially writing the drivers to implement this method, we did want to return the events that were detected, not all of the ones we were listening for. The problem is that with some drivers (like the SYSFS one for example) the interrupt won't have any info on why did you get the interrupt, so you won't really know if the event was caused by a High or Low. We decided to do a very fast check right when we got the interrupt, and if we saw the read value was High, then that would mean that the event was a rising event, and a falling event otherwise. The problem with this implementation is that it was very timing sensitive, as we saw that you might get the rising interrupt before the value changes, so when we perform the read we still see a 0 in value which leads us to think it was a falling event. Same goes for our read taking long, as we also saw sometimes how when you are running multithreaded and have something driving the read value to change very often, there would be times where by the time we were performing the read after getting an interrupt to see the event type, the value had already changed back again because of the other thread causing us to assume the wrong event type. Because we kept on seeing problems like this, we resulted into changing the spec and xml docs and instead having the API just return the events you were listening for as that would ideally be always correct, granted it might not get you the info you want, but it would at least be correct.

[joperezr]

To move forward, we could either think of a better way to detect the event type of the interrupt for all drivers, or on the other hand we should just do what @hidegh proposes and adjust the sample project as it seems to be inferring the wrong assumption now.

[pgrawehr]

Hmmm... I can see your point. At least with the improved Raspi interrupt detection logic I've implemented, I have not seen this problem, though. The interrupt kind was always reported correctly. I'll try to explicitly force the problem once and see whether I get it to happen. I'll also try with SysFs alone.
Do you by chance have the test cases you were testing still somewhere?

To improve the situation, we could also just compare the old value with the new. That would give us also a hint on what happened. (If the values are equal, it was both a rise and a fall [or at least one, but that's impossible to know]). And in the worst case, we could return "Unknown" or something, so that at least we return something useful when the driver supports it (or when it's obvious, because only one edge was listened for).

[joperezr]

Do you by chance have the test cases you were testing still somewhere?

I don't have a test because our current tests are forced to run in a single-thread and I was seeing this problem when running multi-threaded apps which had several controllers on each thread control the value of one output pin which was directly connected to one input pin, and then I was trying to read the events coming in from the input pin on the main thread. Cases like that were the ones where I started seeing inconsistencies specifically when using the SysFS driver.

To improve the situation, we could also just compare the old value with the new.

We tried something like this, but the problem was how to know exactly at what time to take the "old" measurement and at what time to take the "new" one, as there could definitely still be value changes between the point of the interrupt and any of those two readings.

[pgrawehr]

We tried something like this, but the problem was how to know exactly at what time to take the "old" measurement and at what time to take the "new" one, as there could definitely still be value changes between the point of the interrupt and any of those two readings.

@joperezr For WaitForEvent that's true, and there's no way we can guarantee correctness there, because we cannot detect an event while we're not (yet) or no more waiting. But at least we can tell that there was _at least one_ edge in the detected direction.
For the callback variant, it should be possible to be better, because we always know what we last saw. It is still possible that we might miss edges if the pulses are really quick (and detect two pulses as one), but I think that's inherently impossible to detect.

[pgrawehr]

@joperezr I have tried hard, but couldn't reproduce a problem as described. My setup:

• Use a square wave generator, running at 1khz
• Waiting for rising events
• Check that the result correctly indicates they were rising

I tried modifying the duty cycle of the square wave from very short to very long pulses, but I never saw a falling event being detected when reading the state just after I got the interrupt. Note that I did the test without the last change on my branch, which will - by design - never report a wrong edge if only waiting for one edge. I tried with both the Raspi implementation as well as the SysFs implementation. What I did see - and what I also expected - was that the SysFs implementation was much slower and lost a great number of events, while the Raspi implementation only lost events when they became very short (<~100us). I'll try what happens if I'm listening on several pins at the same time. Maybe this will repro the issue.

The situation could still be improved by adding logic that compares previous from next values, as described above, but that's optional, IMHO.

[joperezr]

Thanks for getting that data @pgrawehr I think it is really useful. If that is the case, then we can probably change the API to have both the events being waited on and the events that were detected. We can get a proposal ready for this and check it out with our review board.

[pgrawehr]

Update: Still working on this, without changing much, I'm now getting exactly the problem @joperezr describes, while previously I never saw that. It's all very confusing and takes a lot of time to debug 🕐

[joperezr]

Yeah we also couldn't get an exact repro all the time but did get this issue every now and then, which is why we decided for consistency and went back to just reporting the events to detect.

I will also try getting a repro on this and dedicate some time on trying to think how to get this to work better.

[pgrawehr]

Just fighting with one test now, then I can hopefully complete my PR finally.
The other thread got me an idea, too: I'll try to use libgpiod instead of sysfs for the interrupt handling, if available. That one seems to support returning the type of detected event.