Modbus openHAB2 binding available for alpha testing

Add-ons Bindings
, ,
384

This is working quite well:

Bridge modbus:tcp:EPEVER [ host="192.168.125.128", port=502, id=1, timeBetweenTransactionsMillis=500, timeBetweenReconnectMillis=500, reconnectAfterMillis=0 ] {
	Bridge poller realtime_data1 [start=12548, length=14, refresh=1000, type="input"] {
		Thing data 3104 "Battery voltage"		@ "EPEVER"	[readStart="12548", readValueType="int16", readTransform="JS(divide100.js)"]
		Thing data 310C "Load Voltage"		@ "EPEVER"	[readStart="12556", readValueType="int16", readTransform="JS(divide100.js)"]
		Thing data 3110 "Battery Temperature"			@ "EPEVER"	[readStart="12560", readValueType="int16", readTransform="JS(divide100.js)"]
		Thing data 3111 "Temperature inside equipment"	@ "EPEVER"	[readStart="12561", readValueType="int16", readTransform="JS(divide100.js)"]
	}
	
	Bridge poller realtime_data3 [start=12570, length=1, refresh=1000, type="input"] {
		Thing data 311A "Battery SOC"			@ "EPEVER" [readStart="12570", readValueType="int16" ]
	}
	
	Bridge poller switch_value	[start=2, length=1, maxTries=5, refresh=1000, type="coil"] {
        Thing data 0002 [ readStart="2", readValueType="bit" , writeStart="2", writeValueType="bit", writeType="coil"]
	}
}

What is not working:
Bridge poller switch_value -> if i switch this via openhab everything is messed up again.
Switching this one works fine, as long as refresh=0 on all three pollers.

Here the errors:

2018-04-12 13:31:52.021 [ome.event.ItemCommandEvent] - Item 'EPEVER_0002_switch' received command ON

2018-04-12 13:31:52.029 [vent.ItemStateChangedEvent] - EPEVER_0002_switch changed from OFF to ON

2018-04-12 13:31:52.620 [vent.ItemStateChangedEvent] - EPEVER_3104_number changed from 25.41 to 25.4

2018-04-12 13:31:52.628 [vent.ItemStateChangedEvent] - EPEVER_3104_lastReadSuccess changed from 2018-04-12T13:31:50.699+0200 to 2018-04-12T13:31:52.607+0200

==> /var/log/openhab2/openhab.log <==

2018-04-12 13:31:55.975 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.WriteCoilRequest@14d83b2 (unit id 1 & transaction 1368). Address: /192.168.125.128:502

2018-04-12 13:31:55.981 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.WriteCoilRequest@14d83b2 (unit id 1 & transaction 1368). Address: /192.168.125.128:502

2018-04-12 13:31:55.987 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusWriteCoilRequestBlueprintImpl@16cfbe8[slaveId=1,reference=2,functionCode=WRITE_COIL,bits=SingleBitArray(true),maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID a3b517fc-a961-4b70-9e03-da7db4788fa2]

2018-04-12 13:31:59.508 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@19a58b4 (unit id 1 & transaction 1369). Address: /192.168.125.128:502

2018-04-12 13:31:59.512 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@19a58b4 (unit id 1 & transaction 1369). Address: /192.168.125.128:502

2018-04-12 13:31:59.516 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@1a7eaf3[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12570,length=1,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 78742dd4-f1ab-44b6-b123-1ee072ab1ef0]

2018-04-12 13:32:03.057 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@1c8087b (unit id 1 & transaction 1370). Address: /192.168.125.128:502

2018-04-12 13:32:03.060 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@1c8087b (unit id 1 & transaction 1370). Address: /192.168.125.128:502

2018-04-12 13:32:03.064 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@120789[slaveId=1,functionCode=READ_COILS,start=2,length=1,maxTries=5]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 514012bb-82d2-4df6-a91c-d89314f1864a]

2018-04-12 13:32:06.579 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@a34c50 (unit id 1 & transaction 1371). Address: /192.168.125.128:502

2018-04-12 13:32:06.583 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@a34c50 (unit id 1 & transaction 1371). Address: /192.168.125.128:502

2018-04-12 13:32:06.588 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 80ae9bed-4f8c-4556-af00-806f7aa4f8b5]

2018-04-12 13:32:10.103 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.WriteCoilRequest@11d027b (unit id 1 & transaction 1372). Address: /192.168.125.128:502

2018-04-12 13:32:10.108 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.WriteCoilRequest@11d027b (unit id 1 & transaction 1372). Address: /192.168.125.128:502

2018-04-12 13:32:10.114 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 failed when executing request (ModbusWriteCoilRequestBlueprintImpl@16cfbe8[slaveId=1,reference=2,functionCode=WRITE_COIL,bits=SingleBitArray(true),maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID a3b517fc-a961-4b70-9e03-da7db4788fa2]

2018-04-12 13:32:13.629 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@e331fd (unit id 1 & transaction 1373). Address: /192.168.125.128:502

2018-04-12 13:32:13.631 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@e331fd (unit id 1 & transaction 1373). Address: /192.168.125.128:502

2018-04-12 13:32:13.635 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@1a7eaf3[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12570,length=1,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 78742dd4-f1ab-44b6-b123-1ee072ab1ef0]

2018-04-12 13:32:17.152 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@3eb32e (unit id 1 & transaction 1374). Address: /192.168.125.128:502

2018-04-12 13:32:17.155 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@3eb32e (unit id 1 & transaction 1374). Address: /192.168.125.128:502

2018-04-12 13:32:17.158 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 2 out of 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@120789[slaveId=1,functionCode=READ_COILS,start=2,length=1,maxTries=5]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 514012bb-82d2-4df6-a91c-d89314f1864a]

2018-04-12 13:32:20.672 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@1102a80 (unit id 1 & transaction 1375). Address: /192.168.125.128:502

2018-04-12 13:32:20.676 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@1102a80 (unit id 1 & transaction 1375). Address: /192.168.125.128:502

2018-04-12 13:32:20.683 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 80ae9bed-4f8c-4556-af00-806f7aa4f8b5]

2018-04-12 13:32:24.198 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.WriteCoilRequest@1ce13b7 (unit id 1 & transaction 1376). Address: /192.168.125.128:502

2018-04-12 13:32:24.203 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.WriteCoilRequest@1ce13b7 (unit id 1 & transaction 1376). Address: /192.168.125.128:502

2018-04-12 13:32:24.209 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Last try 3 failed when executing request (ModbusWriteCoilRequestBlueprintImpl@16cfbe8[slaveId=1,reference=2,functionCode=WRITE_COIL,bits=SingleBitArray(true),maxTries=3]). Aborting. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID a3b517fc-a961-4b70-9e03-da7db4788fa2]

2018-04-12 13:32:24.224 [ERROR] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:EPEVER:switch_value:0002 'Modbus data' had ModbusSlaveIOExceptionImpl error on write: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null)

==> /var/log/openhab2/events.log <==

2018-04-12 13:32:24.243 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:switch_value:0002' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with write. Request: ModbusWriteCoilRequestBlueprintImpl@16cfbe8[slaveId=1,reference=2,functionCode=WRITE_COIL,bits=SingleBitArray(true),maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null

==> /var/log/openhab2/openhab.log <==

2018-04-12 13:32:27.725 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@bea531 (unit id 1 & transaction 1377). Address: /192.168.125.128:502

2018-04-12 13:32:27.728 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@bea531 (unit id 1 & transaction 1377). Address: /192.168.125.128:502

2018-04-12 13:32:27.733 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Last try 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@1a7eaf3[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12570,length=1,maxTries=3]). Aborting. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 78742dd4-f1ab-44b6-b123-1ee072ab1ef0]

2018-04-12 13:32:27.744 [ERROR] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:EPEVER:realtime_data3:311A 'Battery SOC' had ModbusSlaveIOExceptionImpl error on read: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null)

==> /var/log/openhab2/events.log <==

2018-04-12 13:32:27.763 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data3:311A' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@1a7eaf3[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12570,length=1,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null

2018-04-12 13:32:27.770 [hingStatusInfoChangedEvent] - 'modbus:poller:EPEVER:realtime_data3' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error with read: org.openhab.io.transport.modbus.internal.ModbusSlaveIOExceptionImpl: null

2018-04-12 13:32:27.777 [vent.ItemStateChangedEvent] - EPEVER_311A_lastReadError changed from 2018-04-12T13:21:34.559+0200 to 2018-04-12T13:32:27.749+0200

2018-04-12 13:32:27.785 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data3:311A' changed from OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@1a7eaf3[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12570,length=1,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null to OFFLINE: Thing disposed -- bridge initializing?

2018-04-12 13:32:27.794 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data3:311A' changed from OFFLINE: Thing disposed -- bridge initializing? to ONLINE

==> /var/log/openhab2/openhab.log <==

2018-04-12 13:32:31.256 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@598f3c (unit id 1 & transaction 1378). Address: /192.168.125.128:502

2018-04-12 13:32:31.261 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@598f3c (unit id 1 & transaction 1378). Address: /192.168.125.128:502

2018-04-12 13:32:31.265 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 3 out of 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@120789[slaveId=1,functionCode=READ_COILS,start=2,length=1,maxTries=5]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 514012bb-82d2-4df6-a91c-d89314f1864a]

2018-04-12 13:32:34.779 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@15f4246 (unit id 1 & transaction 1379). Address: /192.168.125.128:502

2018-04-12 13:32:34.782 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@15f4246 (unit id 1 & transaction 1379). Address: /192.168.125.128:502

2018-04-12 13:32:34.787 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Last try 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]). Aborting. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 80ae9bed-4f8c-4556-af00-806f7aa4f8b5]

2018-04-12 13:32:34.799 [ERROR] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:EPEVER:realtime_data1:3104 'Battery voltage' had ModbusSlaveIOExceptionImpl error on read: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null)

2018-04-12 13:32:34.813 [ERROR] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:EPEVER:realtime_data1:310C 'Load Voltage' had ModbusSlaveIOExceptionImpl error on read: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null)

2018-04-12 13:32:34.824 [ERROR] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:EPEVER:realtime_data1:3110 'Battery Temperature' had ModbusSlaveIOExceptionImpl error on read: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null)

==> /var/log/openhab2/events.log <==

2018-04-12 13:32:34.827 [vent.ItemStateChangedEvent] - EPEVER_3104_lastReadError changed from 2018-04-12T13:21:34.670+0200 to 2018-04-12T13:32:34.805+0200

==> /var/log/openhab2/openhab.log <==

2018-04-12 13:32:34.837 [ERROR] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:EPEVER:realtime_data1:3111 'Temperature inside equipment' had ModbusSlaveIOExceptionImpl error on read: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null)

==> /var/log/openhab2/events.log <==

2018-04-12 13:32:34.858 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3104' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null

2018-04-12 13:32:34.871 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3104' changed from OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null to OFFLINE: Thing disposed -- bridge initializing?

2018-04-12 13:32:34.885 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:310C' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null

2018-04-12 13:32:34.902 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3104' changed from OFFLINE: Thing disposed -- bridge initializing? to ONLINE

2018-04-12 13:32:34.909 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3110' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null

2018-04-12 13:32:34.913 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3111' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null

2018-04-12 13:32:34.920 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3110' changed from OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null to OFFLINE: Thing disposed -- bridge initializing?

2018-04-12 13:32:34.924 [hingStatusInfoChangedEvent] - 'modbus:poller:EPEVER:realtime_data1' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error with read: org.openhab.io.transport.modbus.internal.ModbusSlaveIOExceptionImpl: null

2018-04-12 13:32:34.931 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:310C' changed from OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null to OFFLINE: Thing disposed -- bridge initializing?

2018-04-12 13:32:34.936 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3110' changed from OFFLINE: Thing disposed -- bridge initializing? to ONLINE

2018-04-12 13:32:34.946 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:310C' changed from OFFLINE: Thing disposed -- bridge initializing? to ONLINE

2018-04-12 13:32:34.951 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3111' changed from OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null to OFFLINE: Thing disposed -- bridge initializing?

2018-04-12 13:32:34.958 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:realtime_data1:3111' changed from OFFLINE: Thing disposed -- bridge initializing? to ONLINE

==> /var/log/openhab2/openhab.log <==

2018-04-12 13:32:38.303 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@1c5a0c8 (unit id 1 & transaction 1380). Address: /192.168.125.128:502

2018-04-12 13:32:38.310 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@1c5a0c8 (unit id 1 & transaction 1380). Address: /192.168.125.128:502

2018-04-12 13:32:38.315 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@1a7eaf3[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12570,length=1,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 797c7f52-d1a5-4ee2-98f7-954589d4229c]

2018-04-12 13:32:41.828 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@76a09c (unit id 1 & transaction 1381). Address: /192.168.125.128:502

2018-04-12 13:32:41.830 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@76a09c (unit id 1 & transaction 1381). Address: /192.168.125.128:502

2018-04-12 13:32:41.833 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 4 out of 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@120789[slaveId=1,functionCode=READ_COILS,start=2,length=1,maxTries=5]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 514012bb-82d2-4df6-a91c-d89314f1864a]

2018-04-12 13:32:45.347 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@104b945 (unit id 1 & transaction 1382). Address: /192.168.125.128:502

2018-04-12 13:32:45.351 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@104b945 (unit id 1 & transaction 1382). Address: /192.168.125.128:502

2018-04-12 13:32:45.355 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@43e080[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12548,length=14,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID ae28db66-88a7-4193-922e-eb0154efea0b]

2018-04-12 13:32:48.868 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@218dbe (unit id 1 & transaction 1383). Address: /192.168.125.128:502

2018-04-12 13:32:48.870 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@218dbe (unit id 1 & transaction 1383). Address: /192.168.125.128:502

2018-04-12 13:32:48.874 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@1a7eaf3[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=12570,length=1,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 797c7f52-d1a5-4ee2-98f7-954589d4229c]

2018-04-12 13:32:52.396 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@4a33cb (unit id 1 & transaction 1384). Address: /192.168.125.128:502

2018-04-12 13:32:52.401 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadCoilsRequest@4a33cb (unit id 1 & transaction 1384). Address: /192.168.125.128:502

2018-04-12 13:32:52.407 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Last try 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@120789[slaveId=1,functionCode=READ_COILS,start=2,length=1,maxTries=5]). Aborting. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 514012bb-82d2-4df6-a91c-d89314f1864a]

2018-04-12 13:32:52.422 [ERROR] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:EPEVER:switch_value:0002 'Modbus data' had ModbusSlaveIOExceptionImpl error on read: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null)

==> /var/log/openhab2/events.log <==

2018-04-12 13:32:52.440 [vent.ItemStateChangedEvent] - EPEVER_0002_lastReadError changed from 2018-04-12T13:21:34.739+0200 to 2018-04-12T13:32:52.426+0200

2018-04-12 13:32:52.451 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:switch_value:0002' changed from OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@120789[slaveId=1,functionCode=READ_COILS,start=2,length=1,maxTries=5]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null to OFFLINE: Thing disposed -- bridge initializing?

2018-04-12 13:32:52.456 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:switch_value:0002' changed from OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with write. Request: ModbusWriteCoilRequestBlueprintImpl@16cfbe8[slaveId=1,reference=2,functionCode=WRITE_COIL,bits=SingleBitArray(true),maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null to OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@120789[slaveId=1,functionCode=READ_COILS,start=2,length=1,maxTries=5]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: SocketTimeoutException Read timed out', cause=null). Message: null

2018-04-12 13:32:52.462 [hingStatusInfoChangedEvent] - 'modbus:data:EPEVER:switch_value:0002' changed from OFFLINE: Thing disposed -- bridge initializing? to ONLINE

After 5 Minutes off errors i restartet the Tracer - everything working well again.

Any hints here?

Thank you - Tom

385

As you probably know, this means that data would not be updated. Is that what you want?

“Bridge poller switch_value” and the “EPEVER_0002_switch” in the logs do not tell the corresponding thing and channel. Please paste the item configuration as well.

I’m afraid I do not know how to help you, sounds like problems with the device (Tracer?).

386

sry, here are all of them…
“Bridge poller switch_value” and the “EPEVER_0002_switch” they belong together.

Number		EPEVER_3104_number			"Spannung Batterie: [%s V]"											(gEPEVER, gPVTrend, gPV)	{channel="modbus:data:EPEVER:realtime_data1:3104:number"}
DateTime	EPEVER_3104_lastReadSuccess	"realtime_data1 last read [%1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS]"	<time>	(gEPEVER)					{channel="modbus:data:EPEVER:realtime_data1:3104:lastReadSuccess"}
DateTime	EPEVER_3104_lastReadError	"realtime_data1 last error [%1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS]"	<error>	(gEPEVER)					{channel="modbus:data:EPEVER:realtime_data1:3104:lastReadError"}

Number		EPEVER_310C_number			"Load voltage: [%s V]"												(gEPEVER, gPV)	{channel="modbus:data:EPEVER:realtime_data1:310C:number"}

Number		EPEVER_3110_number			"Temperatur Batterie: [%.2f °C]"									<temperature>	(gEPEVER, gPV)	{channel="modbus:data:EPEVER:realtime_data1:3110:number"}
Number		EPEVER_3111_number			"Temperatur Tracer: [%.2f °C]"										<temperature>	(gEPEVER, gPV)	{channel="modbus:data:EPEVER:realtime_data1:3111:number"}

Number		EPEVER_311A_number			"Battery SOC: [%d %%]"												<bat>	(gEPEVER, gPV)	{channel="modbus:data:EPEVER:realtime_data3:311A:number"}
DateTime	EPEVER_311A_lastReadSuccess	"realtime_data3 last read [%1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS]"	<time>	(gEPEVER)	{channel="modbus:data:EPEVER:realtime_data3:311A:lastReadSuccess"}
DateTime	EPEVER_311A_lastReadError	"realtime_data3 last error [%1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS]"	<error>	(gEPEVER)	{channel="modbus:data:EPEVER:realtime_data3:311A:lastReadError"}

Switch EPEVER_0002_switch      "[%s]"   (gEPEVER)    {channel="modbus:data:EPEVER:switch_value:0002:switch" }	
DateTime	EPEVER_0002_lastReadSuccess	"switch_value last read [%1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS]"	<time>	(gEPEVER)	{channel="modbus:data:EPEVER:switch_value:0002:lastReadSuccess"}
DateTime	EPEVER_0002_lastReadError	"switch_value last error [%1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS]"	<error>	(gEPEVER)	{channel="modbus:data:EPEVER:switch_value:0002:lastReadError"}
String EPEVER_0002_string      "[%s]"   (gEPEVER)    { channel="modbus:data:EPEVER:switch_value:0002:string" }

refresh=0 is not what i want - it was only to test the switch…

To get out of this errors it is helping to restart the Tracer.
It is NOT helping to cut the connection between OH an the Tracer (unpluging the USR) or restarting OH or…

Greetings, Tom

387

One last question - i hope…
What about sending a command - is this made “between” the pollers or simultaneously?

The EPEVER software is able to collect data and send it to the Tracer - so maybe they stop polling before sending?!

Regards

388

Same with commands, the binding makes sure only one connection and one transaction is active to the same device.

I suggest to open new thread regarding this device. Perhaps someone has practical experience with this device.

It certainly sounds that nothing on binding side can help here.

389

Anyone can help to make the Modbus RTU serial work? Please…

390

I recommend opening a new thread regarding this this, it’s a bit buried in this thread.

The binding supports modbus RTU. I am happy to help there when you have the rest ready (arduino etc)

Sami

391

New version available up (23/4) with some fixes and improvements:

  • grouped logging messages

  • update only linked channels (performance optimization)

  • throttling REFRESH commands. This is performance optimization for slower PCs (e.g. raspberry pi 3). When openHAB starts, all channels receive a REFRESH command which will translate to many modbus read requests which are queued. Clearing the queue takes quite some time, which leads to slow updates. UPDATE Apr 23: this was not needed after all – it seems that updating all the channels always was the thing that really suffocated openHAB. Throttling of REFRESH has been removed.

  • Sometimes the transport bundle was not operating properly, and raised the below error [1] (first reported by @gitMiguel here). This error was quite likely when updating the addon.

    Turns out this is an open issue/bug with the 3rd party library Apache pool (for more info POOL-338). It will be fixed eventually upstream, but until then I was able to make a workaround for the bug.

    java.lang.IllegalArgumentException: [org.apache.commons.pool2.impl.DefaultEvictionPolicy] does not implement EvictionPolicy

Best,
Sami

2 Likes
392

Hi All

I have been trying to access my SMA Solar inverter - I have no issues so far using a plain Modbus Poller, but with Modbus bindings for Openhab 2 (The very latest) i’m getting those in my logs:

16:34:07.550 [INFO ] [del.core.internal.ModelRepositoryImpl] - Refreshing model 'sma.things'
16:34:07.564 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@1ef66b81[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@17ea7119[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30769,length=6,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@aff81b6b] (interrupting if necessary)
16:34:07.565 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@1ef66b81[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@17ea7119[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30769,length=6,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@aff81b6b] canceled
16:34:07.574 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:poller:endpointSMA:SMA_Power_A' changed from ONLINE to OFFLINE
16:34:07.593 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@3a46300b[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@8f04dfe[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30957,length=6,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@aff81b6c] (interrupting if necessary)
16:34:07.593 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@3a46300b[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@8f04dfe[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30957,length=6,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@aff81b6c] canceled
16:34:07.599 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'modbus:poller:endpointSMA:SMA_Power_A' has been updated.
16:34:07.606 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Power_A:SMA_Power_A' changed from ONLINE to OFFLINE: Thing disposed -- bridge initializing?
16:34:07.606 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Power_A:SMA_Power_A' changed from OFFLINE: Thing disposed -- bridge initializing? to ONLINE
16:34:07.606 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Power_B:SMA_Power_B' changed from ONLINE to OFFLINE: Thing disposed -- bridge initializing?
16:34:07.607 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Power_B:SMA_Power_B' changed from OFFLINE: Thing disposed -- bridge initializing? to OFFLINE (BRIDGE_OFFLINE): Poller modbus:poller:endpointSMA:SMA_Power_B 'Regular poll' has no poll task
16:34:07.611 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:poller:endpointSMA:SMA_Power_B' changed from ONLINE to OFFLINE
16:34:07.612 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'modbus:poller:endpointSMA:SMA_Power_B' has been updated.
16:34:07.613 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@6024a064[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2a737eb3[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30537,length=2,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@556609ab] (interrupting if necessary)
16:34:07.613 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@6024a064[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2a737eb3[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30537,length=2,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@556609ab] canceled
16:34:07.617 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Daily_Yield:SMA_Daily_Yield' changed from ONLINE to OFFLINE: Thing disposed -- bridge initializing?
16:34:07.617 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:poller:endpointSMA:SMA_Daily_Yield' changed from ONLINE to OFFLINE
16:34:07.617 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Daily_Yield:SMA_Daily_Yield' changed from OFFLINE: Thing disposed -- bridge initializing? to OFFLINE (BRIDGE_OFFLINE): Poller modbus:poller:endpointSMA:SMA_Daily_Yield 'Regular poll' has no poll task
16:34:07.618 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'modbus:poller:endpointSMA:SMA_Daily_Yield' has been updated.

My configuration is:

        Bridge modbus:tcp:endpointSMA [ host="192.168.100.141", port=502, id=3, connectMaxTries=3] {



	Bridge poller SMA_Power_A [ start=30769, length=6, refresh=5000, type="input" ] {
	    
	    	 Thing data SMA_Power_A [ readStart="30773", readValueType="int32", readTransform="JS(divide1000.js)" ]
	    
	   	 
	   	 }



	Bridge poller SMA_Power_B [ start=30957, length=6, refresh=5000, type="input" ] {
	    
	    	 Thing data SMA_Power_B [ readStart="30961", readValueType="int32", readTransform="JS(divide1000.js)" ]
	    	   	 
	   	 }

	Bridge poller SMA_Daily_Yield [ start=30537, length=2, refresh=5000, type="input" ] {
	    
	    	 Thing data SMA_Daily_Yield[ readStart="30537", readValueType="uint32", readTransform="JS(divide1000.js)" ]
	       	 
	   	 }

}

Anyone have an Idea?

393

I don’t see any error really, just things updating which causes things to go OFFLINE momentarily (no ERRORs just INFO)…

What is the final status of things?

Please paste the output or

smarthome:things list

or alternatively screenshot of paper UI things section

394

08
Skærmbillede 2018-04-23 kl. 16.58.08.png2000×544 64.6 KB

66 % is offline, and communication with the device are very slow - when I access the device from ModbusPoll (Test Util) there are no issues.

395

Can you please open one of the data things and take a screenshot of the status message?

396

50
Skærmbillede 2018-04-23 kl. 17.01.50.png2020×1062 195 KB

397

and can you do the same for Poller modbus:poller:endpointSMA:SMA_Power_B?

398

29
Skærmbillede 2018-04-23 kl. 17.07.29.png1334×180 16.4 KB

399

very interesting…

Full logs appreciated if you can share those.

To resolve the situation, can you please try out (one step at a time)

  1. refresh the things (e.g. by adding a comment to things file, and then save it)?
  2. restart openhab?
400

Yes sure - Can you explain how I enable full logging?

401

Thank you Sami. I will open a new thread for it.

Just to clarify. There is a Modbus binding on the Openhab2 that is different from the Eclipse Marketplace (Modbus Binding and Modbus transport).

Can you explain the differences and the reason for these two bindings for Modbus? They are two different ways to work with Modbus?

402

I meant that I would be interested in the full logs since the current log snippet does not reveal the whole chain of events, specifically, when the pollers comes back ONLINE.

P.s. As FYI enabling verbose logs is explained in the docs. I don’t think it would give more insight though in this situation. Even INFO level should be enough

403

I have just tried your suggestion one by one, but the result is the same

17:15:40.602 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_cool_kVA changed from 0.033 to 0.035
17:15:40.714 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_nilan_V changed from 237.2 to 236.9
17:15:41.653 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_srv_A changed from 4.263 to 4.244
17:15:41.654 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_srv_HZ changed from 50.0 to 49.9
17:15:41.656 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_srv_V changed from 234.8 to 233.9
17:15:41.662 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_srv_kW changed from 0.586 to 0.59
17:15:41.664 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_srv_kVA changed from 0.96 to 0.953
17:15:42.670 [INFO ] [del.core.internal.ModelRepositoryImpl] - Refreshing model 'sma.things'
17:15:42.680 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@5b8f3e59[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@fc19800[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30769,length=6,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@aff81b6b] (interrupting if necessary)
17:15:42.681 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@5b8f3e59[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@fc19800[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30769,length=6,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@aff81b6b] canceled
17:15:42.693 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Power_A:SMA_Power_A' changed from ONLINE to OFFLINE: Thing disposed -- bridge initializing?
17:15:42.694 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Power_A:SMA_Power_A' changed from OFFLINE: Thing disposed -- bridge initializing? to ONLINE
17:15:42.695 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:poller:endpointSMA:SMA_Power_A' changed from ONLINE to OFFLINE
17:15:42.701 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@4f72ede5[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@41ecfa2f[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30957,length=6,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@aff81b6c] (interrupting if necessary)
17:15:42.708 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@4f72ede5[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@41ecfa2f[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30957,length=6,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@aff81b6c] canceled
17:15:42.709 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'modbus:poller:endpointSMA:SMA_Power_A' has been updated.
17:15:42.714 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:poller:endpointSMA:SMA_Power_B' changed from ONLINE to OFFLINE
17:15:42.716 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task PollTaskImpl@6f628c6d[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@61a56ff1[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30537,length=2,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@556609ab] (interrupting if necessary)
17:15:42.717 [INFO ] [ort.modbus.internal.ModbusManagerImpl] - Poll task PollTaskImpl@6f628c6d[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@61a56ff1[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30537,length=2,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@773beafa[address=192.168.100.141,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@556609ab] canceled
17:15:42.719 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Power_B:SMA_Power_B' changed from OFFLINE (BRIDGE_OFFLINE): Poller modbus:poller:endpointSMA:SMA_Power_B 'Regular poll' has no poll task to OFFLINE: Thing disposed -- bridge initializing?
17:15:42.720 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Power_B:SMA_Power_B' changed from OFFLINE: Thing disposed -- bridge initializing? to OFFLINE (BRIDGE_OFFLINE): Poller modbus:poller:endpointSMA:SMA_Power_B 'Regular poll' has no poll task
17:15:42.720 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'modbus:poller:endpointSMA:SMA_Power_B' has been updated.
17:15:42.721 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:poller:endpointSMA:SMA_Daily_Yield' changed from ONLINE to OFFLINE
17:15:42.722 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Daily_Yield:SMA_Daily_Yield' changed from OFFLINE (BRIDGE_OFFLINE): Poller modbus:poller:endpointSMA:SMA_Daily_Yield 'Regular poll' has no poll task to OFFLINE: Thing disposed -- bridge initializing?
17:15:42.722 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'modbus:data:endpointSMA:SMA_Daily_Yield:SMA_Daily_Yield' changed from OFFLINE: Thing disposed -- bridge initializing? to OFFLINE (BRIDGE_OFFLINE): Poller modbus:poller:endpointSMA:SMA_Daily_Yield 'Regular poll' has no poll task
17:15:42.725 [INFO ] [smarthome.event.ThingUpdatedEvent    ] - Thing 'modbus:poller:endpointSMA:SMA_Daily_Yield' has been updated.
17:15:43.935 [INFO ] [smarthome.event.ItemStateChangedEvent] - Nilan_Input_T8_Outdoor changed from 12.27 to 12.25
17:15:44.303 [INFO ] [smarthome.event.ItemStateChangedEvent] - Co2_Sove changed from 710 to 711
17:15:44.304 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'Nilan_Control_VentSet' received command 2
17:15:44.305 [INFO ] [smarthome.event.ItemCommandEvent     ] - Item 'Smarthouse_Motorventil' received command OFF
17:15:44.905 [INFO ] [smarthome.event.ItemStateChangedEvent] - Nilan_Time_Second changed from 39 to 46
17:15:45.404 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_AL2 changed from 0.812 to 0.85
17:15:45.404 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_AL3 changed from 0.773 to 0.766
17:15:45.499 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_kW changed from 0.183 to 0.185
17:15:45.500 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_kW2 changed from 0.06 to 0.067
17:15:45.579 [INFO ] [smarthome.event.ItemStateChangedEvent] - Udv_humidity changed from 69.0 to 69.1
17:15:45.580 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_kW3 changed from 0.124 to 0.118
17:15:45.592 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_kVA changed from 0.368 to 0.375
17:15:45.595 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_kVA_L2 changed from 0.192 to 0.196
17:15:45.595 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_kVA_L3 changed from 0.185 to 0.186
17:15:45.596 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_HZ changed from 56.5 to 50.5
17:15:45.648 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_V_L1_L2 changed from 235.8 to 236.2
17:15:45.648 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_V_L2_L3 changed from 411.4 to 412.4
17:15:45.649 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_V_L2_N changed from 236.7 to 242.5
17:15:45.650 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_V_L3_L1 changed from 242.0 to 242.4
17:15:45.650 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM24_Energi_24_V_L3_N changed from 238.9 to 242.4
17:15:45.686 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_cool_A changed from 0.145 to 0.148
17:15:45.699 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_cool_V changed from 236.9 to 237.7
17:15:45.699 [INFO ] [smarthome.event.ItemStateChangedEvent] - EM111_Energi_cool_kW changed from 0.032 to 0.033
'''