Modbus openHAB2 binding available for alpha testing

Hi @ssalonen,

Once more thanks a lot for your help on the serial connection!
Since i’m still busy with experiments on how to do the final implementation of the modbus communication in OpenHAB, I’m now doing a small experiment with the use a TCP connection.

I encounter a rather small problem but worth mentioning in my opinion.
Here you can find my current config (which should be more or less final): https://pastebin.com/LfxJt734

The problem I encounter occurs at startup.
As you can see in the config I keep the connection open for 5 minutes via reconnectAfterMillis.
But at startup it looks like the modbus binding doesn’t use this parameter since it opens and closes every 10 seconds 7 new connections to the slave (because of the 7 pollers I’ve defined that refresh every 10 seconds).

Now, there seems to be a simple “fix” for this. In my case I save the things file again, this causes all poll tasks to be unregistered (see info/error messages bellow), and after that everything is going fine and only one connection remains.

These info/error messages appear after saving the things file again:

2017-09-11 16:23:46.879 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@5364bc3f[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@535cbf28[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4027,length=8],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1587] (interrupting if necessary)
2017-09-11 16:23:46.880 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@6a04e204[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@459a1708[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4021,length=5],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1586] (interrupting if necessary)
2017-09-11 16:23:46.880 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@1865a804[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6990e825[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4015,length=5],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1585] (interrupting if necessary)
2017-09-11 16:23:46.881 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@7d5b2382[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@393927aa[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4000,length=12],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1584] (interrupting if necessary)
2017-09-11 16:23:46.881 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@222c6581[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3ff7ac94[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4036,length=9],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1588] (interrupting if necessary)
2017-09-11 16:23:46.881 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@6a04e204[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@459a1708[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4021,length=5],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1586] canceled
2017-09-11 16:23:46.881 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@222c6581[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3ff7ac94[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4036,length=9],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1588] canceled
2017-09-11 16:23:46.882 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@5364bc3f[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@535cbf28[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4027,length=8],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1587] canceled
2017-09-11 16:23:46.882 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@6e4afca9[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7b7d943f[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4046,length=5],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1589] (interrupting if necessary)
2017-09-11 16:23:46.882 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@7d5b2382[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@393927aa[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4000,length=12],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1584] canceled
2017-09-11 16:23:46.883 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@7c6b98ea[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@a18561c[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4052,length=5],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe158a] (interrupting if necessary)
2017-09-11 16:23:46.883 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@1865a804[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6990e825[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4015,length=5],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1585] canceled
2017-09-11 16:23:46.883 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@7c6b98ea[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@a18561c[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4052,length=5],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe158a] canceled
2017-09-11 16:23:46.884 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@6825c617[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3671cfc7[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4015,length=5],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1585] (interrupting if necessary)
2017-09-11 16:23:46.884 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@6825c617[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3671cfc7[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4015,length=5],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1585] canceled
2017-09-11 16:23:46.885 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@7b7dbe00[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@78698d96[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4021,length=5],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1586] (interrupting if necessary)
2017-09-11 16:23:46.885 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@7b7dbe00[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@78698d96[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4021,length=5],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1586] canceled
2017-09-11 16:23:46.885 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@3c8b1d88[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3ac1e856[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4027,length=8],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1587] (interrupting if necessary)
2017-09-11 16:23:46.885 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@6dde750c[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2b8d13de[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4036,length=9],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1588] (interrupting if necessary)
2017-09-11 16:23:46.885 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@3c8b1d88[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3ac1e856[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4027,length=8],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1587] canceled
2017-09-11 16:23:46.886 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@52ad96cf[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@362ea64f[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4052,length=5],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe158a] (interrupting if necessary)
2017-09-11 16:23:46.886 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@52ad96cf[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@362ea64f[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4052,length=5],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe158a] canceled
2017-09-11 16:23:46.885 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@6dde750c[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2b8d13de[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4036,length=9],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1588] canceled
2017-09-11 16:23:46.887 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@6e4afca9[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7b7d943f[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4046,length=5],endpoint=ModbusTCPSlaveEndpoint@7fff2661[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1589] canceled
2017-09-11 16:23:46.884 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@a1c3d4[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@69b6c4b5[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4000,length=12],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1584] (interrupting if necessary)
2017-09-11 16:23:46.887 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@a1c3d4[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@69b6c4b5[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4000,length=12],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1584] canceled
2017-09-11 16:23:46.888 [WARN ] [odbus.handler.ModbusReadThingHandler] - Poller 'Poll definition' of ReadWrite bridge 'Modbus read-write definition' of ReadThing 'Modbus read definition' has no poll task. Aborting config validation
2017-09-11 16:23:46.889 [WARN ] [odbus.handler.ModbusReadThingHandler] - Poller 'Poll definition' of ReadWrite bridge 'Modbus read-write definition' of ReadThing 'Modbus read definition' has no poll task. Aborting config validation
2017-09-11 16:23:46.890 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Error getting a new connection for endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]. Error was: java.lang.InterruptedException null
2017-09-11 16:23:46.890 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Not connected to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502] -- aborting request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@69b6c4b5[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4000,length=12]
2017-09-11 16:23:46.901 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@42b0da59[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4c010eb8[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4000,length=12],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1584] (interrupting if necessary)
2017-09-11 16:23:46.891 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Poll task was unregistered -- not executing/proceeding with the poll
org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollTaskUnregistered: Poll task PollTaskImpl@a1c3d4[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@69b6c4b5[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4000,length=12],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1584] is unregistered
	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.verifyTaskIsRegistered(ModbusManagerImpl.java:400) ~[?:?]
	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOneTimePoll(ModbusManagerImpl.java:433) ~[?:?]
	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$11(ModbusManagerImpl.java:500) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
2017-09-11 16:23:46.902 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@42b0da59[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4c010eb8[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4000,length=12],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1584] canceled
2017-09-11 16:23:46.900 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Error getting a new connection for endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]. Error was: java.lang.InterruptedException null
2017-09-11 16:23:46.903 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Not connected to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502] -- aborting request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2b8d13de[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4036,length=9]
2017-09-11 16:23:46.899 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@3928ef77[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3bb977ca[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4046,length=5],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1589] (interrupting if necessary)
2017-09-11 16:23:46.905 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@3928ef77[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3bb977ca[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4046,length=5],endpoint=ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@5dbe1589] canceled
2017-09-11 16:23:46.906 [WARN ] [.handler.ModbusReadWriteThingHandler] - Read write thing handler got read error: org.openhab.io.transport.modbus.internal.ModbusConnectionException Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]
2017-09-11 16:23:46.897 [WARN ] [odbus.handler.ModbusReadThingHandler] - Poller 'Poll definition' of ReadWrite bridge 'Modbus read-write definition' of ReadThing 'Modbus read definition' has no poll task. Aborting config validation
2017-09-11 16:23:46.909 [ERROR] [odbus.handler.ModbusReadThingHandler] - Thing Modbus read definition received read error: org.openhab.io.transport.modbus.internal.ModbusConnectionException Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]. Stack trace follows for unexpected errors.
org.openhab.io.transport.modbus.internal.ModbusConnectionException: Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]
	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$5(ModbusManagerImpl.java:436) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
2017-09-11 16:23:46.913 [WARN ] [.handler.ModbusReadWriteThingHandler] - Read write thing handler got read error: org.openhab.io.transport.modbus.internal.ModbusConnectionException Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]
2017-09-11 16:23:46.915 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Error when executing read request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@78698d96[slaveId=11,functionCode=READ_MULTIPLE_REGISTERS,start=4021,length=5]): net.wimpi.modbus.ModbusIOException Thread acquiring lock was interrupted.
2017-09-11 16:23:46.914 [ERROR] [odbus.handler.ModbusReadThingHandler] - Thing Modbus read definition received read error: org.openhab.io.transport.modbus.internal.ModbusConnectionException Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]. Stack trace follows for unexpected errors.
org.openhab.io.transport.modbus.internal.ModbusConnectionException: Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]
	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$5(ModbusManagerImpl.java:436) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
2017-09-11 16:23:46.918 [WARN ] [.handler.ModbusReadWriteThingHandler] - Read write thing handler got read error: org.openhab.io.transport.modbus.internal.ModbusConnectionException Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]
2017-09-11 16:23:46.918 [ERROR] [odbus.handler.ModbusReadThingHandler] - Thing Modbus read definition received read error: org.openhab.io.transport.modbus.internal.ModbusConnectionException Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]. Stack trace follows for unexpected errors.
org.openhab.io.transport.modbus.internal.ModbusConnectionException: Error connecting to endpoint ModbusTCPSlaveEndpoint@7b30305b[address=192.168.50.113,port=502]
	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$5(ModbusManagerImpl.java:436) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]

Another important note is that sometimes, at startup I also see this unregistering appearing at startup. In this case everything is fine from startup and I don’t need to save the things file again to fix it.

Question: is there a reason why the connection should be closed after every poll operation or after the timeout defined by reconnectAfterMillis? Isn’t it also fine to leave the connection permanently open?

Thanks!

Greetings,
Frederic

Hi,

thanks for reporting this. I think you might be seeing some sort of transient since things are initializing / changing and thus it might just dispose / re-create some of things “automatically”.

It would help you can repeat the experiment with verbose logging, also include debug level logs from openhab itself, if possible.

Need to try this out also once we have thing structure/hierachy stabilized.

Question: is there a reason why the connection should be closed after every poll operation or after the timeout defined by reconnectAfterMillis? Isn’t it also fine to leave the connection permanently open?

You can probably find some old discussions regarding this but long story short, keeping connection open for a long time is a problem for some users as some modbus slaves support only one outbound connection. This means that other “clients” would be blocked when openHAB accesses the slave.

As with most parameters with the binding, the default setting is conservative and closes connection after every poll (connection time is minimized).

Also, closing connection might be considered more safe/robust by some, as the everything is flushed/cleared between modbus transactions.

Hi,

I’ve uploaded 3 log different log files from different tests via WeTransfer.
Here is the download link: https://we.tl/vAERN610gD

So I did 3 runs with different results:

  • openhab_all_ok.log: here everything went fine, so after startup, only one connection to the slave was created.
  • openhab_not_ok.log: after startup, every 10 seconds, 7 connections are created and closed to the slave.
  • openhab_ok_after_save_at_47-40.log: in this log I had the same effect as the log before (7 connections every 10 seconds) but I saved the things file again during operation which resulted in the expected behavior. This reloading is seen at this point in the log file:
2017-09-12 09:47:35.966 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'modbus.things'

I’ve enabled trace logging on both the binding and the transport service.
In the log configuration I’ve put the root logger to debug as also the smarthome and openhab logging.

I hope these log files can give an indication on what is going on.

Greetings,
Frederic

1 Like

Hi @ssalonen,

Have you found the time to download the files?
I’ve uploaded them with a free account so they will be deleted in 13 hours from now.
If not, let me know so I can upload them again :slight_smile:

Greetings,
Frederic

Thanks, I have now downloaded the files but have not yet time to look into the actual logs.

Really good to have this, I can at least see quite much verbose information on things being created by openHAB so this should help understanding the issue a bit more

Sami

EDIT: hey, in order to debug the logs I need to confirm whether the timestamps in the logs are local time or UTC? Can you double-check this please?

Hi,

The timestamps are local time.

Thanks!

Greetings,
Frederic

What is local time over your server? :smiley:

My time zone is UTC+1 (Belgium)

Thanks!

The logs have been really useful. What I can say that there seems to be inverted boolean logic in the code that determines whether to disconnect the connection or not – this happens after every transaction.

In fact, it seems that connection is disconnected now always, in both the ok and “not ok” logs.

I will post updated version during the next few days and let’s see how that works out.

1 Like

Hi All

Sorry if this is off-topic.

The new modbus binding, will it support Uint64/int64 by any chance?

Hi

No that’s not off-topic at all! Currently it does not but it is certainly pretty straight forward to implement.

The new binding supports reading of bit, int8, and uint8 from registers. Read/write is supported with int16, uint16, int32, uint32, float32 (+ word swapped versions of the 32bit types).

int64, Uint64 would really be a nice thing, as more and more new devices starts using it :slight_smile:

Hope you guys will consider implement it.

Can you give example of such devices? Are they bringing in double (64 bit float) support as well?

Sami

P.S. @Nanna_Agesen: if you are willing to contribute to the codebase, I can help you to get started as well!

Im currently working with a Carlo Gavazzi Energy Meter (Em24), connected to their Smart-House controller UPW Platform.

They have Uint64 input registers as (4 word)

Also the SMA solar inverter uses Uint input registers for their total Kwh counter.

I sure will :slight_smile:

Yeah found the manual here http://www.support-carlogavazzi.se/downloads\Controls\EM271%20MODBUS%20V0R0%20ENG.pdf

And

Sma http://files.sma.de/dl/24399/STP60-SunSpec_Modbus-TI-en-12.pdf

Indeed they talk about int64/uint64 but not double float (64bit).

The relevant change should happen in modbus transport https://github.com/ssalonen/openhab2-addons/blob/modbus-openhab2-native-binding/addons/io/org.openhab.io.transport.modbus/src/main/java/org/openhab/io/transport/modbus/ModbusBitUtilities.java. Tests are here

A new ValueType needs to be added. As there are 4 registers, there are quite many possible register orderings: abcd, abdc, bacd, badc, cdab, cdba, etc. . With 16 bit types there are only two (non-swap and swap). Due to amount of variations it might make sense to implement only abcd first, rest can be added later when/if need arises. One can use transformations also to do the word swap.

If this looks complicated you can wait for this new feature, perhaps I have some time in future to implement it.

Best
Sami

I can see that it’s a but more complicated than 16 bit types registers - It would be great if we could have it supported in the future :slight_smile:

For now I do have a problem with Uint32 holding registers, maybe you have a clue what im doing wrong.

#Stue - Temperatur Setpoint 1
tcp.slave61.connection=192.168.100.86:502:60:0:0:3:100
tcp.slave61.type=holding
tcp.slave61.id=1
tcp.slave61.start=845
tcp.slave61.length=2
tcp.slave61.valuetype=uint32_swap

I need to swap the two registers to get the correct value, but when I try to write a new value I get this error in console:

09:56:28.192 [ERROR] [.binding.modbus.internal.ModbusSlave] - ModbusSlave (slave61): error when executing write request (net.wimpi.modbus.msg.WriteMultipleRegistersRequest@28558de0): Error Code = 3

The WriteMultipleRegisters is set to true, and also the cached modbus.config has been deleted after a shutdown .

I think you are using the old binding. Can you please open a new post since this thread is about the new version?

Short story is that with old binding that is a known limitation, see the bolded disclaimer in the docs http://docs.openhab.org/addons/bindings/modbus1/readme.html#write

The old binding writes the number as 16bit integer, which is probably not what you want. The slave returns error code, probably because we are trying to write single register and not two.

Sorry just read about the limitation - the new binding is that backwards compatible?

It is not backwards compatible. Actually the point is to introduce things and channels and therefore it cannot be backwards compatible.

The new Binding just works perfect :slight_smile:

Finally able to apply setpoint for heating in my house.

Do you see any problems running the old 1.10 Binding Parallel with the new one - while migrating all existing code ?