Memory leak with Nikobus in 1.7.1?

Pascal,

Yes it was tested with 1.7.0 runtime and 1.7.0 nikobus bindings.

I also have send an email to Davy Vanherbergen, the author of the nikobus binding, and he doesn’t have the problem in 1.4…
I will ask him again that he can check it in 1.7.1

Marc

Marc, what is the version number of your switch module?

Davy, the module is 05-000-02. Where can I find the version number?

That is the version number. The old one was version 05-000-01.
Did you ever get an outofmemory exception? if not, there is no memory leak.

Your log shows:

java.util.concurrent.TimeoutException: No ACK received within timeout and retry count.

This means that openHAB sent a request for an updated status to your nikobus module, but it never received a response from your nikobus module. If you enable debug logging, you should be able to see what commands are being sent on the serial bus. Posting debug logging could help to troubleshoot the issue.
As you mention that you can still send commands to the nikobus, this would indicate that the serial connection is still working, which would seem to indicate your switch module is misbehaving.
Do you only have one nikobus module? If you have more than one, does the issue occur with both?

Davy,

I have 6 switch-modules. And the problem is with all of them.
That is a debug-log that I have posted.
What version of switch-modules do you use?

05-000-02. So that should be OK.

There is no nikobus debug output in your log. Did you add this to your log config?

<logger name="org.openhab.binding.nikobus" level="DEBUG" />

I will verify it…

Davy,

Here is a piece of the log-file after the feedback stop working.

java.util.concurrent.TimeoutException: No ACK received within timeout and retry count. at org.openhab.binding.nikobus.internal.core.NikobusAckMonitor.waitForAck(NikobusAckMonitor.java:92) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding.sendCommand(NikobusBinding.java:158) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding$2.run(NikobusBinding.java:295) ~[na:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0] at java.lang.Thread.run(Thread.java:744) [na:1.8.0] 20:54:35.463 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $10174235073799 20:54:37.485 [ERROR] [.o.b.n.internal.NikobusBinding:297 ] - Error occurred during scheduled status refresh. java.util.concurrent.TimeoutException: No ACK received within timeout and retry count. at org.openhab.binding.nikobus.internal.core.NikobusAckMonitor.waitForAck(NikobusAckMonitor.java:92) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding.sendCommand(NikobusBinding.java:158) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding$2.run(NikobusBinding.java:295) ~[na:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0] at java.lang.Thread.run(Thread.java:744) [na:1.8.0] 21:04:36.463 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $10127253E5328D 21:04:38.502 [ERROR] [.o.b.n.internal.NikobusBinding:297 ] - Error occurred during scheduled status refresh. java.util.concurrent.TimeoutException: No ACK received within timeout and retry count. at org.openhab.binding.nikobus.internal.core.NikobusAckMonitor.waitForAck(NikobusAckMonitor.java:92) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding.sendCommand(NikobusBinding.java:158) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding$2.run(NikobusBinding.java:295) ~[na:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0] at java.lang.Thread.run(Thread.java:744) [na:1.8.0]

Could you restart openhab and then post a log starting from the last time the refresh worked until the first time it fails?
Are you using the PC-Link module? Do you have any rules or anything else which sends commands to the nikobus?

Davy,

I’m using de PC-logic module to connect to OpenHab. I have tested it with the PC-link, and have the same problem.
I don’ use rules

07:36:01.012 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$0512, repeats=1] 07:36:01.214 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$1CFF38000000FF0000FF991A31, repeats=1] 07:36:01.215 [DEBUG] [.n.i.config.ModuleChannelGroup:233 ] - Processing nikobus command $1CFF38000000FF0000FF991A31 for module (FF38-1) 07:43:14.154 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=#N70EF52, repeats=5] 07:43:14.157 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $1012FF38553BBA 07:43:14.200 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$0512, repeats=1] 07:43:14.777 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=#N70EF52, repeats=3] 07:43:15.525 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$1CFF38000000FF0000FF991A31, repeats=1] 07:43:15.527 [DEBUG] [.n.i.config.ModuleChannelGroup:233 ] - Processing nikobus command $1CFF38000000FF0000FF991A31 for module (FF38-1) 07:43:15.529 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $1012FF38553BBA 07:43:15.572 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$0512, repeats=1] 07:43:15.773 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$1CFF38000000FF0000FF991A31, repeats=1] 07:43:15.774 [DEBUG] [.n.i.config.ModuleChannelGroup:233 ] - Processing nikobus command $1CFF38000000FF0000FF991A31 for module (FF38-1) 07:43:16.287 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=#N30EF52, repeats=4] 07:43:16.290 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $1012FF38553BBA 07:43:16.335 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$0512, repeats=1] 07:43:17.018 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$1CFF38000000FF00FFFF9AE5F8, repeats=1] 07:43:17.019 [DEBUG] [.n.i.config.ModuleChannelGroup:233 ] - Processing nikobus command $1CFF38000000FF00FFFF9AE5F8 for module (FF38-1) 07:46:01.968 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $1017FF38BECB99 07:46:02.013 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$0517, repeats=1] 07:46:02.224 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=$1CFF3800000000000000CC496E, repeats=1] 07:46:02.225 [DEBUG] [.n.i.config.ModuleChannelGroup:233 ] - Processing nikobus command $1CFF3800000000000000CC496E for module (FF38-2) 07:49:31.590 [DEBUG] [b.n.i.c.NikobusCommandReceiver:161 ] - Received NikobusCommand [command=#N478032, repeats=1] 07:56:02.968 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $1017423367F191 07:56:05.028 [ERROR] [.o.b.n.internal.NikobusBinding:297 ] - Error occurred during scheduled status refresh. java.util.concurrent.TimeoutException: No ACK received within timeout and retry count. at org.openhab.binding.nikobus.internal.core.NikobusAckMonitor.waitForAck(NikobusAckMonitor.java:92) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding.sendCommand(NikobusBinding.java:158) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding$2.run(NikobusBinding.java:295) ~[na:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0] at java.lang.Thread.run(Thread.java:744) [na:1.8.0] 08:06:03.968 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $10172936E084C0 08:06:05.989 [ERROR] [.o.b.n.internal.NikobusBinding:297 ] - Error occurred during scheduled status refresh. java.util.concurrent.TimeoutException: No ACK received within timeout and retry count. at org.openhab.binding.nikobus.internal.core.NikobusAckMonitor.waitForAck(NikobusAckMonitor.java:92) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding.sendCommand(NikobusBinding.java:158) ~[na:na] at org.openhab.binding.nikobus.internal.NikobusBinding$2.run(NikobusBinding.java:295) ~[na:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0] at java.lang.Thread.run(Thread.java:744) [na:1.8.0] 08:16:04.968 [DEBUG] [.o.b.n.i.core.NikobusInterface:233 ] - Sending : $101242338C01D3 08:16:06.989 [ERROR] [.o.b.n.internal.NikobusBinding:297 ] - Error occurred during scheduled status refresh. java.util.concurrent.TimeoutException: No ACK received within timeout and retry count.

The successful status loads and the failing ones appear to be for different modules. Could you send me the full log via email?
Just to double check: all 6 modules are type 05-000-02, right?

Davy,

I will send you the full log via email.
All switch-modules are 05-000-02

I checked your log file and noticed something odd. It appears that every time the feedback starts failing, this occurs immediately after button N478032 was pressed. I’m wondering if that button may be broken and is sending invalid data on the bus.

Can you increase the log level to trace, restart openhab and press that button? This will show all the traffic on the nikobus. If the button is sending something odd, it should show up. If my theory is right, the feedback should also start failing right after the button press.
To activate the trace, you need to update the log config to the following:

<logger name="org.openhab.binding.nikobus" level="TRACE" />

Alternatively, you could try to not use that button for a while and see if the feedback keeps working.

Thank you, I will try it.

Davy,

Thank you for the support.
I found a error in my items file for that button. There was a wrong adress of the module for reading back the status, an adress that didn’t exist.
Now it keep on working after pressing that button.:grinning:
Tomorrow, I will see that everything is still working.

Great!

Already one day working without problem.
I think the problem is solved, because before it didn’t work that long!!

:grinning::grinning::grinning:

Great!!

So I can conclude that there is no bug, and I can safely purchase my module?

Sorry for raising a false issue Davy!
Thanks for your support!

Until now, everything keep on working. Now more than one day

Yep. It’s working fine. I got my pc-link module on a second hand website. Sometimes there are people that buy one just to configure their system and then sell it again.
Alternatively, if you are a maker, I can get you in touch with some people who have designed a compatible PCB board. I’m not sure how complex it would be to build as that is out of my comfort zone…