Input Listener get stuck

[Ir3nicuz]

I'm facing an issue with pi4j 2.6.0 on a Pi4, for which I need support how to analyse and track down the issue.

I'm using the lib to control several GPIO as digital outputs and reading GPIO 22 as digital input.
Therefore I registrate a event listener to the DigitalInput object.

The issue is that the input event listening works reliable several times, but sporadic "suddenly" this happens:
The input event is no longer fired, regardeless how often the GPIO ist triggered from the circuit. 1 of the 4 pi cores (linux core monitor app) jumps from 5% to 100% utilisation. All other used functions of the lib (I2C, DigOuts, ...) still working perfectly. Only the event of this GPIO seems to get stuck. After closing the program the core utilisation returns to 0%. After restarting the program the input event working properly again.

Since I got no exception i have no idea how to track this behaviour down to the root cause.
Maybe it could be a mechanical bouncing issue of the switch or maybe a multithread access issue.
Is there a logging option to supervise the input state responsible for this lib function?

The whole java program is relatively big. So i not post the whole program. If special code sections are interesting I will post this sections on request.

[taartspi]

To view available logging in the pi4j java files:

in directory /src/main/resources
Create file simplelogger.properties

Add entry org.slf4j.simpleLogger.defaultLogLevel=TRACE

If you are asking more questions on this post, as your post says you moved to 2.6.0 SNAPSHOT, please copy paste the boardinfo details described here https://www.pi4j.com/documentation/board-info/ And say which providers you are using, Hopefully the trace provides some info of where normal operation faltered.

[taartspi]

If having this detail captured and including a timestamp is of assistance these are more items that you can place into the properties file.

org.slf4j.simpleLogger.defaultLogLevel=TRACE

# enable a single class logging as TRACE
#org.slf4j.simpleLogger.log.com.pi4j.provider.impl=TRACE

#  With simple logger you can have logging to a file OR the console

# Directory /tmp/logs must exist !
org.slf4j.simpleLogger.logFile=/tmp/logs/foo

#org.slf4j.simpleLogger.logFile=System.out


org.slf4j.simpleLogger.showDateTime=true

org.slf4j.simpleLogger.dateTimeFormat=yyyy-MM-dd HH:mm:ss:SSS Z  
    

Also, you questioned whether your switch was bouncing, there is a debounce parm available.

        this.inputConfig1 = DigitalInput.newConfigBuilder(pi4j)
                .id("Data_In")
                .name("Data_In")
                .address(this.dataPinNum)
                .pull(PullResistance.OFF)
                .debounce(10)
                .provider("gpiod-digital-input");

[Ir3nicuz]

Thanks for the hints.

I activated the logging. Shortly before the shutdown in the log the described issue happend.
pi4jLog.log

I use the providers linuxfs-i2c, pigpio-pwm, pigpio-digital-input and pigpio-digital-output.

I already had a debounce property of 50ms set for GPIO 22. But this is just a guess. No idea if it covers the real bounce spikes.
Pi4jContext.create(DigitalInput.newConfigBuilder(Pi4jContext) .provider("pigpio-digital-input") .address(gpioNumber) .pull(pullMode) .debounce(50));

The only conspicuousness i found in the log file is, that the "get" entries for GPIO 22 appear in multiple "gets" within only milliseconds.
This is not intended by my program. If have no "polling" of the state implemented. I call a manual "get" at some time beside the event listener. But not at such speed and not that often.
On the other side i saw no "Event" in the logs. How can I seperate programmatical "gets" from input events triggered by GPIO 22?

Here are the Board Info Outputs:
Pi4j Board model: Raspberry Pi 3 Model B
Pi4j Operating system: Name: Linux, version: 6.1.21-v7+, architecture: arm
Pi4j Java versions: Version: 17.0.9, runtime: 17.0.9+9-Raspbian-1deb11u1rpt1, vendor: Raspbian, vendor version: null
Pi4j Raspberry Pi model with RP1 chip (Raspberry Pi 5): false
Pi4j OS is 64-bit: false
Pi4j JVM memory used (MB): 4.25286865234375
Pi4j Board temperature (°C): 52.1

[taartspi]

It looks like 22 is the only input pin so it has the listener.
Also looking at the log there is a pattern where 22 goes high then 18 set low, then 22 goes low and 18 set high.
At the end where you said the the problem has happened and events stop, 22 went high and 18 was set high, then 18 is continually set low set high.
I do not know what the event handler code does or how any of the output pins are used in the HW. But I think understanding why the pattern was broken is required to debug.

[Ir3nicuz]

GPIO 22 is the only digital input I have and GPIO 18 is one of several digital outputs.

The intended pattern is that GPIO 22 is high and GPIO 18 toggles every 250ms after startup.
If GPIO 22 is pulled low the fired event handler should stop GPIO 18 from toggling and GPIO 18 should remain in the last state.
After a software trigger from my program the toggling of GPIO 18 should start again until the next high to low transistion of GPIO 22.

I will have a deeper look in the log file and analyse the results. This file is a great help.

One point I do not understand in the log semantic.
GPIO 22 is an input. So the lib could get a "getState" call from my program. Or a "fire event" trigger if the GPIO22 state is changed from the connected circuit. How can i differ this in the log?
I see only "gets". So I would assume an event is never raised and all the "gets" belonging to "getState" calls of my program.
But cannot be correct since my program reacts on the external event most times correct.

[taartspi]

I believe you are asking for details when your event fires, my suggestion is add logging into your code. Place it in the event handler and other important steps in your java code. Use the traces to document code flow when operating correctly and the steps that lead up to the problem occurring.

Copied portions of java core code as an example of this coding

 protected Logger logger = LoggerFactory.getLogger(this.getClass());

In a method

            logger.debug("[INITIALIZE] -- INITIALIZED SUCCESSFULLY");

[Ir3nicuz]

Of course, I'm logging the event handling step by step in my program already.
I just thought comparing the event handling in my program with the event trigger input at the lib could give additional hints.
But if that is not possible, its ok.

[eitch]

In your log i can see, that the event handler is being fired due to the different threads: pool-3-thread-1

Can you perhaps perform a head dump, when this 100% CPU utilization is reached? This does not sound good. Can you add loggers when you enter your handler, and when you leave the handler? Perhaps that may help as well a bit.

[Ir3nicuz]

I already found the root cause.

In the event handler I had Thread.interrupt() and i had to wait for the interruption. There seems to be some magical cases where an Thread.interrupt() is ignored. And therefore the wait for the interruption never moves on.

I refactored the section to a scheduledThreadPool and all runs perfect. Thanks for the hints.

[eitch]

I am glad your issue is solved!