Modbus Binding not working on OH3

JamesC · December 28, 2020, 2:34am

I have noticed that sometimes after restarting OH the modbus driver connects to /dev/ttyUSB0 and scans for a short period.

2020-12-28 12:05:12.257 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Modbus manager activated
2020-12-28 12:05:14.471 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 22740.0703125 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:14.479 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 23587.986328125 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:14.757 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 232.8000030517578 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:16.376 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusReadRequestBlueprint@750128a6[slaveId=2,functionCode=READ_INPUT_REGISTERS,start=0,length=26,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: IOException Error reading response (EOF) [operation ID 1efe5d3c-52fc-4bb8-b4aa-ab80a9b91aa3]
2020-12-28 12:05:18.087 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 failed when executing request (ModbusReadRequestBlueprint@750128a6[slaveId=2,functionCode=READ_INPUT_REGISTERS,start=0,length=26,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: IOException Error reading response (EOF) [operation ID 1efe5d3c-52fc-4bb8-b4aa-ab80a9b91aa3]
2020-12-28 12:05:18.405 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 212.10000610351562 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:28.573 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 375.8999938964844 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:35.186 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 233.6999969482422 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:38.737 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 444.8999938964844 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:45.348 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 233.6999969482422 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:48.899 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 353.6000061035156 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:55.516 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 234.8000030517578 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:05:59.061 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 353.79998779296875 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:06:05.692 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 234.10000610351562 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2020-12-28 12:06:10.680 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusReadRequestBlueprint@750128a6[slaveId=2,functionCode=READ_INPUT_REGISTERS,start=0,length=26,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: IOException CRC Error in received frame: 20 bytes: 02 04 34 43 6a 99 9a 00 00 00 00 00 00 00 00 40 8e 14 7b 00  [operation ID 18669b5d-0237-4a79-8bfb-3bdc22c8ade6]
2020-12-28 12:06:10.726 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@63985ba9[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@62875a6c[portName=/dev/ttyUSB0]
2020-12-28 12:06:11.728 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 2/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@63985ba9[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@62875a6c[portName=/dev/ttyUSB0]
2020-12-28 12:06:12.730 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 3/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@63985ba9[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@62875a6c[portName=/dev/ttyUSB0]
2020-12-28 12:06:12.731 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - re-connect reached max tries 3, throwing last error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@63985ba9[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@62875a6c[portName=/dev/ttyUSB0]
2020-12-28 12:06:12.731 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@63985ba9[portName=/dev/ttyUSB0,port=<null>] for endpoint ModbusSerialSlaveEndpoint@62875a6c[portName=/dev/ttyUSB0]: Could not get port identifier, maybe insufficient permissions. null
2020-12-28 12:06:12.732 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Could not connect to endpoint ModbusSerialSlaveEndpoint@62875a6c[portName=/dev/ttyUSB0] -- aborting request ModbusReadRequestBlueprint@750128a6[slaveId=2,functionCode=READ_INPUT_REGISTERS,start=0,length=26,maxTries=3] [operation ID 18669b5d-0237-4a79-8bfb-3bdc22c8ade6]
2020-12-28 12:06:14.491 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@330971ec[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@3dce99fd[portName=/dev/ttyUSB0]
2020-12-28 12:06:15.493 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 2/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@330971ec[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@3dce99fd[portName=/dev/ttyUSB0]
2020-12-28 12:06:16.495 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 3/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@330971ec[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@3dce99fd[portName=/dev/ttyUSB0]
2020-12-28 12:06:16.496 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - re-connect reached max tries 3, throwing last error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@330971ec[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@3dce99fd[portName=/dev/ttyUSB0]
2020-12-28 12:06:16.497 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@330971ec[portName=/dev/ttyUSB0,port=<null>] for endpoint ModbusSerialSlaveEndpoint@3dce99fd[portName=/dev/ttyUSB0]: Could not get port identifier, maybe insufficient permissions. null

The ModbusDataThingHandler is updating values. A CRC error is detected and the connection is reset. From there I start seeing “Could not get port identifier, maybe insufficient permissions.”.

Maybe there is an issue with the connection being reset and the port not being properly closed before opening the new connection?

Rado1 · December 28, 2020, 5:58pm

I just had the same problem after updating to openHAB3 (stable) .I ended up doing a completely fresh install and everything worked back.

JamesC · December 29, 2020, 7:49pm

Thanks for the suggestion, I did a fresh install and still the same.

ssalonen · December 29, 2020, 7:59pm

Possibly related?

Cc @fwolter

JamesC · December 29, 2020, 8:49pm

Thanks @ssalonen.

I think this is likely to be the issue I am seeing.

On further investigation I believe one of my modbus meters is a bit flaky and is the source of some errors on the serial comms. This issue is the modbus binding tries to reset the connection to the serial USB dongle and never recovers. This trace shows the issue.

2020-12-30 06:30:18.858 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Sent: 01 03 00 00 00 02 c4 0b 
2020-12-30 06:30:18.937 [TRACE] [t.wimpi.modbus.io.ModbusRTUTransport] - Managed to read at least one byte
2020-12-30 06:30:18.939 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Response: 01 03 04 00 00 00 00 fa 33 
2020-12-30 06:30:18.940 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:5cd13db2 received response PollResult(result=AsyncModbusReadResult(request = ModbusReadRequestBlueprint@44d90d0b[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=2,maxTries=3], registers = ModbusRegisterArray(00000000)))
2020-12-30 06:30:18.941 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel number will be updated to '0.0' (type DecimalType). Input data: number value 0.0 (value type 'float32' taken into account) and bool value false. Transformation: <identity>
2020-12-30 06:30:18.941 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel datetime will be updated to '1970-01-01T00:00:00.000+0000' (type DateTimeType). Input data: number value 0.0 (value type 'float32' taken into account) and bool value false. Transformation: <identity>
2020-12-30 06:30:18.942 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel string will be updated to '0.0' (type StringType). Input data: number value 0.0 (value type 'float32' taken into account) and bool value false. Transformation: <identity>
2020-12-30 06:30:18.942 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel contact will be updated to 'CLOSED' (type OpenClosedType). Input data: number value 0.0 (value type 'float32' taken into account) and bool value false. Transformation: <identity>
2020-12-30 06:30:18.942 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will be updated to '0.0' (type PercentType). Input data: number value 0.0 (value type 'float32' taken into account) and bool value false. Transformation: <identity>
2020-12-30 06:30:18.943 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel dimmer will be updated to 'OFF' (type OnOffType). Input data: number value 0.0 (value type 'float32' taken into account) and bool value false. Transformation: <identity>
2020-12-30 06:30:18.943 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0.0 (value type 'float32' taken into account) and bool value false. Transformation: <identity>
2020-12-30 06:30:18.944 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:279dfdcd channels updated: {modbus:data:279dfdcd:string=0.0, modbus:data:279dfdcd:contact=CLOSED, modbus:data:279dfdcd:switch=OFF, modbus:data:279dfdcd:datetime=1970-01-01T00:00:00.000+0000, modbus:data:279dfdcd:number=0.0, modbus:data:279dfdcd:dimmer=OFF, modbus:data:279dfdcd:lastReadSuccess=2020-12-30T06:30:18.943775+1000, modbus:data:279dfdcd:rollershutter=0.0}. readValueType=float32, readIndex=Optional[0], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 0.0 and boolValue=false. Registers ModbusRegisterArray(00000000) for request ModbusReadRequestBlueprint@44d90d0b[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=2,maxTries=3]
2020-12-30 06:30:26.180 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Sent: 03 04 00 00 00 1a 70 23 
2020-12-30 06:30:27.683 [TRACE] [t.wimpi.modbus.io.ModbusRTUTransport] - Managed to read at least one byte
2020-12-30 06:30:27.683 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 03 04 00 00 00 1a 70 23
2020-12-30 06:30:27.684 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2020-12-30 06:30:27.685 [DEBUG] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/1 error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@b23f1db (unit id 3 & transaction 308). Serial parameters: SerialParameters@71e04e1[portName=/dev/ttyUSB0,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-12-30 06:30:27.686 [DEBUG] [pi.modbus.io.ModbusSerialTransaction] - execute reached max tries 1, throwing last error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@b23f1db (unit id 3 & transaction 308). Serial parameters: SerialParameters@71e04e1[portName=/dev/ttyUSB0,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-12-30 06:30:27.700 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusReadRequestBlueprint@2da23ae5[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=0,length=26,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: IOException Error reading response (EOF) [operation ID a2d0827e-a588-4c8a-a031-2ef17427447d]
2020-12-30 06:30:27.809 [DEBUG] [et.wimpi.modbus.net.SerialConnection] - Could not get port identifier, maybe insufficient permissions. gnu.io.NoSuchPortException: null
2020-12-30 06:30:27.810 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@1e97cc78[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@2dc25b5c[portName=/dev/ttyUSB0]
2020-12-30 06:30:28.812 [DEBUG] [et.wimpi.modbus.net.SerialConnection] - Could not get port identifier, maybe insufficient permissions. gnu.io.NoSuchPortException: null
2020-12-30 06:30:28.813 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 2/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@1e97cc78[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@2dc25b5c[portName=/dev/ttyUSB0]
2020-12-30 06:30:29.814 [DEBUG] [et.wimpi.modbus.net.SerialConnection] - Could not get port identifier, maybe insufficient permissions. gnu.io.NoSuchPortException: null
2020-12-30 06:30:29.815 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 3/3 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@1e97cc78[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@2dc25b5c[portName=/dev/ttyUSB0]
2020-12-30 06:30:29.816 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - re-connect reached max tries 3, throwing last error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@1e97cc78[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@2dc25b5c[portName=/dev/ttyUSB0]
2020-12-30 06:30:29.816 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@1e97cc78[portName=/dev/ttyUSB0,port=<null>] for endpoint ModbusSerialSlaveEndpoint@2dc25b5c[portName=/dev/ttyUSB0]: Could not get port identifier, maybe insufficient permissions. null
2020-12-30 06:30:29.819 [DEBUG] [et.wimpi.modbus.net.SerialConnection] - Could not get port identifier, maybe insufficient permissions. gnu.io.NoSuchPortException: null

Will refer my issue to the bug in github

fwolter · December 29, 2020, 8:59pm

@JamesC You could try the patched JAR I posted here: Modbus binding loses its serial connection every few days without a reason after updating to 2.5.0 Release Build - #16 by fwolter

JamesC · December 30, 2020, 11:20am

@fwolter thanks for pointing to the JAR file. Unfortunately it didn’t help.

fwolter · December 30, 2020, 11:44am

Did you add EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0" to /etc/default/openhab as stated here Serial Port Configuration | openHAB?

JamesC · December 30, 2020, 8:32pm

Added the EXTRA_JAVA_OPTS and it is looking better. Will continue to monitor over the next few days. Thanks greatly appreciated.

fwolter · January 1, 2021, 11:49am

Did you have success with or without the patched JAR?

JamesC · January 1, 2021, 8:03pm

Adding the EXTRA_JAVA_OPTS fixed the issue. I was using the patched JAR but have now reverted to the original and it’s working.

JamesC · January 2, 2021, 8:22pm

The modbus polling stopped after 12 hours with the original JAR. I have gone back to the patched JAR and see how that goes.

lampy · January 4, 2021, 4:44pm

Did the patched JAR work for you?
I do have the same symptoms, reading out modbus stops after approx 12h w/o any warning.

I’m not always able to react quickly, but below a screenshot of the voltage. This line is changing constanly, until the modbus stops functioning. After restart openhab (sudo sysemctl restart openhab) the modbus starts working again.
On OH2 it worked ok, difference is OH2 on RPI3 instead RPI4.
Modbus device is SDM120.

Done until now:

created symlinks
added symlink to openhab.service
used the updated .jar as shown above

Today I reinstalled ZRAM since this configuration has been changed, perhaps this helps. Are there any other idea’s to try if this does not help?

p.s. if I should post this to a own tread let me know, but since the symptoms where so similar I thought perhaps better to post it here first.

JamesC · January 4, 2021, 8:40pm

@lampy, the issue you describe has the same symptoms to what I am seeing. I also use an SDM120.

The patched JAR had been working continuously for 2 days but has now failed. The patch JAR is better but the issue still exists. Suggest you update to the patched JAR and turn the modbus DEBUG logging on to capture more info. I am doing the same.

lampy · January 4, 2021, 9:27pm

Ok! Set debug logging on, let’s see what we have tomorrow

lampy · January 5, 2021, 11:41am

@JamesC This morning the modbus stopped working again, here below the logs:

2021-01-05 04:53:41.917 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ApparentPower channels updated: {}. readValueType=float32, readIndex=Optional[18], readSubIndex(or 0)=0, extractIndex=18 -> numeric value 377.86651611328125 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:41.920 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ReactivePower channels updated: {}. readValueType=float32, readIndex=Optional[24], readSubIndex(or 0)=0, extractIndex=24 -> numeric value -365.1000061035156 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:41.923 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:PowerFactor channels updated: {modbus:data:endpointSDM120:inputRegisters:PowerFactor:number=0.25716885924339294}. readValueType=float32, readIndex=Optional[30], readSubIndex(or 0)=0, extractIndex=30 -> numeric value 0.25716885924339294 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:41.926 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:PhaseAngle channels updated: {}. readValueType=float32, readIndex=Optional[36], readSubIndex(or 0)=0, extractIndex=36 -> numeric value 0.0 and boolValue=false. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:41.930 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:Frequency channels updated: {modbus:data:endpointSDM120:inputRegisters:Frequency:number=50.0}. readValueType=float32, readIndex=Optional[70], readSubIndex(or 0)=0, extractIndex=70 -> numeric value 50.0 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:41.933 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ImportActiveEnergy channels updated: {}. readValueType=float32, readIndex=Optional[72], readSubIndex(or 0)=0, extractIndex=72 -> numeric value 1718.68505859375 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:41.935 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ExportActiveEnergy channels updated: {}. readValueType=float32, readIndex=Optional[74], readSubIndex(or 0)=0, extractIndex=74 -> numeric value 0.0 and boolValue=false. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:41.938 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ImportReactiveEnergy channels updated: {modbus:data:endpointSDM120:inputRegisters:ImportReactiveEnergy:number=17.885000228881836}. readValueType=float32, readIndex=Optional[76], readSubIndex(or 0)=0, extractIndex=76 -> numeric value 17.885000228881836 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:41.940 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ExportReactiveEnergy channels updated: {}. readValueType=float32, readIndex=Optional[78], readSubIndex(or 0)=0, extractIndex=78 -> numeric value 2361.3798828125 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB020C000000000000000042C23333000000000000000043BCEEEA0000000000000000C3B68CCD00000000000000003E83ABA3000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.811 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:endpointSDM120:inputRegisters received response PollResult(result=AsyncModbusReadResult(request = ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3], registers = ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614)))
2021-01-05 04:53:43.813 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:Voltage channels updated: {modbus:data:endpointSDM120:inputRegisters:Voltage:number=227.10000610351562}. readValueType=float32, readIndex=Optional[0], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 227.10000610351562 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.815 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:Current channels updated: {modbus:data:endpointSDM120:inputRegisters:Current:number=1.7139999866485596}. readValueType=float32, readIndex=Optional[6], readSubIndex(or 0)=0, extractIndex=6 -> numeric value 1.7139999866485596 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.820 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ActivePower channels updated: {modbus:data:endpointSDM120:inputRegisters:ActivePower:number=98.69999694824219}. readValueType=float32, readIndex=Optional[12], readSubIndex(or 0)=0, extractIndex=12 -> numeric value 98.69999694824219 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.822 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ApparentPower channels updated: {}. readValueType=float32, readIndex=Optional[18], readSubIndex(or 0)=0, extractIndex=18 -> numeric value 378.81805419921875 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.825 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ReactivePower channels updated: {}. readValueType=float32, readIndex=Optional[24], readSubIndex(or 0)=0, extractIndex=24 -> numeric value -365.70001220703125 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.829 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:PowerFactor channels updated: {modbus:data:endpointSDM120:inputRegisters:PowerFactor:number=0.260623574256897}. readValueType=float32, readIndex=Optional[30], readSubIndex(or 0)=0, extractIndex=30 -> numeric value 0.260623574256897 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.830 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:PhaseAngle channels updated: {}. readValueType=float32, readIndex=Optional[36], readSubIndex(or 0)=0, extractIndex=36 -> numeric value 0.0 and boolValue=false. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.834 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:Frequency channels updated: {modbus:data:endpointSDM120:inputRegisters:Frequency:number=50.0}. readValueType=float32, readIndex=Optional[70], readSubIndex(or 0)=0, extractIndex=70 -> numeric value 50.0 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.837 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ImportActiveEnergy channels updated: {}. readValueType=float32, readIndex=Optional[72], readSubIndex(or 0)=0, extractIndex=72 -> numeric value 1718.68505859375 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.839 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ExportActiveEnergy channels updated: {}. readValueType=float32, readIndex=Optional[74], readSubIndex(or 0)=0, extractIndex=74 -> numeric value 0.0 and boolValue=false. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.842 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ImportReactiveEnergy channels updated: {modbus:data:endpointSDM120:inputRegisters:ImportReactiveEnergy:number=17.885000228881836}. readValueType=float32, readIndex=Optional[76], readSubIndex(or 0)=0, extractIndex=76 -> numeric value 17.885000228881836 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:43.845 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ExportReactiveEnergy channels updated: {}. readValueType=float32, readIndex=Optional[78], readSubIndex(or 0)=0, extractIndex=78 -> numeric value 2361.3798828125 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDB645A000000000000000042C56666000000000000000043BD68B60000000000000000C3B6D99A00000000000000003E857074000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D5EC00000000418F147B45139614) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:53:46.850 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: IOException Error reading response (EOF) [operation ID c0d86404-44f2-411a-aff4-f5eaa0849f95]
2021-01-05 05:04:29.310 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = xxxxxxxx, base URL = http://localhost:8080)
2021-01-05 05:05:20.354 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = xxxxxxx, base URL = http://localhost:8080)

The WARN message comes back more often:

2021-01-05 04:35:37.814 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ImportReactiveEnergy channels updated: {modbus:data:endpointSDM120:inputRegisters:ImportReactiveEnergy:number=17.885000228881836}. readValueType=float32, readIndex=Optional[76], readSubIndex(or 0)=0, extractIndex=76 -> numeric value 17.885000228881836 and boolValue=true. Registers ModbusRegisterArray(4363333300000000000000003FDB4396000000000000000042C2999A000000000000000043BD3B080000000000000000C3B6D99A00000000000000003E83C3D2000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D4FE00000000418F147B45139452) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:35:37.817 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ExportReactiveEnergy channels updated: {}. readValueType=float32, readIndex=Optional[78], readSubIndex(or 0)=0, extractIndex=78 -> numeric value 2361.27001953125 and boolValue=true. Registers ModbusRegisterArray(4363333300000000000000003FDB4396000000000000000042C2999A000000000000000043BD3B080000000000000000C3B6D99A00000000000000003E83C3D2000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004248000044D6D4FE00000000418F147B45139452) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:35:40.821 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: IOException Error reading response (EOF) [operation ID fea1fcfa-218f-404d-a431-fd9bdae62a8a]
2021-01-05 04:35:41.307 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:endpointSDM120:inputRegisters received response PollResult(result=AsyncModbusReadResult(request = ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3], registers = ModbusRegisterArray(4363333300000000000000003FDB4396000000000000000042C4999A000000000000000043BD3B0F0000000000000000C3B6B33300000000000000003E8512DF000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004247CCCD44D6D4FE00000000418F147B45139456)))
2021-01-05 04:35:41.310 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:Voltage channels updated: {modbus:data:endpointSDM120:inputRegisters:Voltage:number=227.1999969482422}. readValueType=float32, readIndex=Optional[0], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 227.1999969482422 and boolValue=true. Registers ModbusRegisterArray(4363333300000000000000003FDB4396000000000000000042C4999A000000000000000043BD3B0F0000000000000000C3B6B33300000000000000003E8512DF000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004247CCCD44D6D4FE00000000418F147B45139456) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:35:41.314 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:Current channels updated: {modbus:data:endpointSDM120:inputRegisters:Current:number=1.7130000591278076}. readValueType=float32, readIndex=Optional[6], readSubIndex(or 0)=0, extractIndex=6 -> numeric value 1.7130000591278076 and boolValue=true. Registers ModbusRegisterArray(4363333300000000000000003FDB4396000000000000000042C4999A000000000000000043BD3B0F0000000000000000C3B6B33300000000000000003E8512DF000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004247CCCD44D6D4FE00000000418F147B45139456) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]

2021-01-05 04:51:53.421 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ImportReactiveEnergy channels updated: {modbus:data:endpointSDM120:inputRegisters:ImportReactiveEnergy:number=17.885000228881836}. readValueType=float32, readIndex=Optional[76], readSubIndex(or 0)=0, extractIndex=76 -> numeric value 17.885000228881836 and boolValue=true. Registers ModbusRegisterArray(4363000000000000000000003FDB4396000000000000000042C43333000000000000000043BCD0540000000000000000C3B64CCD00000000000000003E852261000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004247CCCD44D6D5D300000000418F147B451395E7) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:51:53.426 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:ExportReactiveEnergy channels updated: {}. readValueType=float32, readIndex=Optional[78], readSubIndex(or 0)=0, extractIndex=78 -> numeric value 2361.368896484375 and boolValue=true. Registers ModbusRegisterArray(4363000000000000000000003FDB4396000000000000000042C43333000000000000000043BCD0540000000000000000C3B64CCD00000000000000003E852261000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004247CCCD44D6D5D300000000418F147B451395E7) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:51:56.430 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: IOException Error reading response (EOF) [operation ID 5b9b51f3-2094-43e1-b718-89f2df624f67]
2021-01-05 04:51:56.859 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:endpointSDM120:inputRegisters received response PollResult(result=AsyncModbusReadResult(request = ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3], registers = ModbusRegisterArray(4363199A00000000000000003FDAE148000000000000000042C20000000000000000000043BCD05B0000000000000000C3B6733300000000000000003E839EC1000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004247CCCD44D6D5DB00000000418F147B451395E7)))
2021-01-05 04:51:56.862 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:Voltage channels updated: {modbus:data:endpointSDM120:inputRegisters:Voltage:number=227.10000610351562}. readValueType=float32, readIndex=Optional[0], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 227.10000610351562 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDAE148000000000000000042C20000000000000000000043BCD05B0000000000000000C3B6733300000000000000003E839EC1000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004247CCCD44D6D5DB00000000418F147B451395E7) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]
2021-01-05 04:51:56.865 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:endpointSDM120:inputRegisters:Current channels updated: {modbus:data:endpointSDM120:inputRegisters:Current:number=1.7100000381469727}. readValueType=float32, readIndex=Optional[6], readSubIndex(or 0)=0, extractIndex=6 -> numeric value 1.7100000381469727 and boolValue=true. Registers ModbusRegisterArray(4363199A00000000000000003FDAE148000000000000000042C20000000000000000000043BCD05B0000000000000000C3B6733300000000000000003E839EC1000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004247CCCD44D6D5DB00000000418F147B451395E7) for request ModbusReadRequestBlueprint@1aa1c08[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=80,maxTries=3]

I had updated to the new .jar from @fwolter already earlier.

Screenshot of symlinks:

Screenshot of openhab file:

Output of command lsusb

[12:35:56] openhabian@openHAB3:~$ lsusb
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 007: ID 1cf1:0030 Dresden Elektronik
Bus 001 Device 006: ID 0658:0200 Sigma Designs, Inc. Aeotec Z-Stick Gen5 (ZW090) - UZB
Bus 001 Device 005: ID 1a86:7523 QinHeng Electronics HL-340 USB-Serial adapter
Bus 001 Device 004: ID 1a40:0101 Terminus Technology Inc. Hub
Bus 001 Device 003: ID 14cd:1212 Super Top microSD card reader (SY-T18)
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

To make it all complete, here my .things file:

Bridge modbus:serial:endpointSDM120 [port="/dev/ttyUSBMODBUS",baud=9600,id=1,dataBits=8,parity="none",stopBits="1.0",encoding="rtu"] {
    Bridge poller inputRegisters [ start=0, length=80, refresh=1500, type="input" ] {
        Thing data Voltage                       "Voltage" @ "Mains"                            [ readStart="0", readValueType="float32" ]
        Thing data Current                       "Current" @ "Mains"                             [ readStart="6", readValueType="float32" ]
        Thing data ActivePower                   "Active Power" @ "Mains"                        [ readStart="12", readValueType="float32" ]
        Thing data ApparentPower                 "Apparent Power" @ "Mains"                      [ readStart="18", readValueType="float32" ]
        Thing data ReactivePower                 "Reactive Power" @ "Mains"                      [ readStart="24", readValueType="float32" ]
        Thing data PowerFactor                   "Power Factor" @ "Mains"                        [ readStart="30", readValueType="float32" ]
        Thing data PhaseAngle                    "Phase Angle" @ "Mains"                          [ readStart="36", readValueType="float32" ]
        Thing data Frequency                     "Frequency" @ "Mains"                            [ readStart="70", readValueType="float32" ]
        Thing data ImportActiveEnergy            "Import Active Energy" @ "Mains"                 [ readStart="72", readValueType="float32" ]
        Thing data ExportActiveEnergy            "Export Active Energy" @ "Mains"                [ readStart="74", readValueType="float32" ]
        Thing data ImportReactiveEnergy          "Import Reactive Energy" @ "Mains"              [ readStart="76", readValueType="float32" ]
        Thing data ExportReactiveEnergy          "Export Reactive Energy" @ "Mains"             [ readStart="78", readValueType="float32" ]
        
	}}

JamesC · January 6, 2021, 7:46pm

I also had the modus stop working with the new JAR installed. It held up for about two days.
The readings flatline:

The modus things remain online:

The logfile shows:

2021-01-06 11:44:45.213 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:afad3afb channels updated: {modbus:data:afad3afb:number=5.0, modbus:data:afad3afb:datetime=1970-01-01T00:00:05.000+0000, modbus:data:afad3afb:contact=OPEN, modbus:data:afad3afb:string=5.0, modbus:data:afad3afb:lastReadSuccess=2021-01-06T11:44:45.213639+1000, modbus:data:afad3afb:dimmer=ON, modbus:data:afad3afb:rollershutter=5.0, modbus:data:afad3afb:switch=ON}. readValueType=float32, readIndex=Optional[2], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 5.0 and boolValue=true. Registers ModbusRegisterArray(40A00000) for request ModbusReadRequestBlueprint@67a36a15[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=2,length=2,maxTries=3]
2021-01-06 11:44:46.036 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Sent: 01 04 00 48 00 0c 70 19 
2021-01-06 11:44:46.154 [TRACE] [t.wimpi.modbus.io.ModbusRTUTransport] - Managed to read at least one byte
2021-01-06 11:44:46.155 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Response: 01 04 18 46 b9 3c 05 46 b3 3d dc 44 12 da 9e 46 43 a0 1e 47 3d 4b 47 48 04 d2 df c5 43 
2021-01-06 11:44:46.156 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:29600f78 received response PollResult(result=AsyncModbusReadResult(request = ModbusReadRequestBlueprint@60b1042b[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=72,length=12,maxTries=3], registers = ModbusRegisterArray(46B93C0546B33DDC4412DA9E4643A01E473D4B474804D2DF)))
2021-01-06 11:44:46.156 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel number will be updated to '22942.9296875' (type DecimalType). Input data: number value 22942.9296875 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.157 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel datetime will be updated to '1970-01-01T06:22:22.000+0000' (type DateTimeType). Input data: number value 22942.9296875 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.157 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel string will be updated to '22942.9296875' (type StringType). Input data: number value 22942.9296875 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.157 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel contact will be updated to 'OPEN' (type OpenClosedType). Input data: number value 22942.9296875 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.157 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 22942.9296875 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.158 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel dimmer will be updated to 'ON' (type OnOffType). Input data: number value 22942.9296875 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.158 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'ON' (type OnOffType). Input data: number value 22942.9296875 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.158 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:2b4a8a03 channels updated: {modbus:data:2b4a8a03:string=22942.9296875, modbus:data:2b4a8a03:datetime=1970-01-01T06:22:22.000+0000, modbus:data:2b4a8a03:dimmer=ON, modbus:data:2b4a8a03:number=22942.9296875, modbus:data:2b4a8a03:lastReadSuccess=2021-01-06T11:44:46.158427+1000, modbus:data:2b4a8a03:switch=ON, modbus:data:2b4a8a03:contact=OPEN}. readValueType=float32, readIndex=Optional[74], readSubIndex(or 0)=0, extractIndex=2 -> numeric value 22942.9296875 and boolValue=true. Registers ModbusRegisterArray(46B93C0546B33DDC4412DA9E4643A01E473D4B474804D2DF) for request ModbusReadRequestBlueprint@60b1042b[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=72,length=12,maxTries=3]
2021-01-06 11:44:46.159 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel number will be updated to '23710.009765625' (type DecimalType). Input data: number value 23710.009765625 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.159 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel datetime will be updated to '1970-01-01T06:35:10.000+0000' (type DateTimeType). Input data: number value 23710.009765625 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.159 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel string will be updated to '23710.009765625' (type StringType). Input data: number value 23710.009765625 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.159 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel contact will be updated to 'OPEN' (type OpenClosedType). Input data: number value 23710.009765625 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.160 [WARN ] [ernal.handler.ModbusDataThingHandler] - Channel rollershutter will not be updated since transformation was unsuccessful. Channel is expecting the following data types [PercentType, UpDownType, UnDefType]. Input data: number value 23710.009765625 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.160 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel dimmer will be updated to 'ON' (type OnOffType). Input data: number value 23710.009765625 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.160 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'ON' (type OnOffType). Input data: number value 23710.009765625 (value type 'float32' taken into account) and bool value true. Transformation: <identity>
2021-01-06 11:44:46.160 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:dcc865e8 channels updated: {modbus:data:dcc865e8:contact=OPEN, modbus:data:dcc865e8:switch=ON, modbus:data:dcc865e8:string=23710.009765625, modbus:data:dcc865e8:dimmer=ON, modbus:data:dcc865e8:number=23710.009765625, modbus:data:dcc865e8:datetime=1970-01-01T06:35:10.000+0000, modbus:data:dcc865e8:lastReadSuccess=2021-01-06T11:44:46.160549+1000}. readValueType=float32, readIndex=Optional[72], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 23710.009765625 and boolValue=true. Registers ModbusRegisterArray(46B93C0546B33DDC4412DA9E4643A01E473D4B474804D2DF) for request ModbusReadRequestBlueprint@60b1042b[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=72,length=12,maxTries=3]
2021-01-06 11:44:50.665 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Sent: 03 04 00 00 00 1a 70 23 
2021-01-06 11:44:52.167 [TRACE] [t.wimpi.modbus.io.ModbusRTUTransport] - Managed to read at least one byte
2021-01-06 11:44:52.167 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 03 04 00 00 00 1a 70 23
2021-01-06 11:44:52.168 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2021-01-06 11:44:52.168 [DEBUG] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/1 error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@7d832fa1 (unit id 3 & transaction 32803). Serial parameters: SerialParameters@29c14505[portName=/dev/ttyUSB0,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2021-01-06 11:44:52.168 [DEBUG] [pi.modbus.io.ModbusSerialTransaction] - execute reached max tries 1, throwing last error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@7d832fa1 (unit id 3 & transaction 32803). Serial parameters: SerialParameters@29c14505[portName=/dev/ttyUSB0,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2021-01-06 11:44:52.169 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusReadRequestBlueprint@6c4ff397[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=0,length=26,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: IOException Error reading response (EOF) [operation ID 284c3879-8e30-407c-817e-f24255cfe433]
2021-01-06 11:44:52.228 [TRACE] [et.wimpi.modbus.net.SerialConnection] - Got Port Identifier

@fwolter please see the log files from the patched JAR.

fwolter · January 6, 2021, 8:02pm

Which OH version are you using? The patched JAR was built for a milestone release. Maybe it doesn’t have an effect anymore.

rossko57 · January 6, 2021, 11:24pm

This is ordinary enough, Modbus is robust enough to retry failed transfers.
So, there should afterwards be a “try 2 out of 3” warn - or - an ordinary working update.
Do you have any more Modbus log entries after this point? If not, it suggests the binding is messing up somewhere in setting up the retry.

lampy · January 7, 2021, 7:33am

After this error no more modbus related logs are shown. Not from the debug level nor the item updates.
Should we file an issue somewhere?