Modbus Configuration Error on ModbusSlaveIOException

Tags: #<Tag:0x00007f433725c8e0>

Hi all, I am having some issues with the ModBus binding with ModBusTCP.

Intermittenly I am getting errors I cannot connect to my setup whether is correct or not.

Can someone help please?

My things file is as below:

Bridge modbus:tcp:riscVmc [ host="192.168.0.17", port=8899, id=1 ] {
  Bridge poller holdings0015 [ start=0, length=16, refresh=2000, type="holding" ] {
    Thing data ventolaEspulsione00 @"VMC" [ readStart="0", readValueType="int16", writeStart="0", writeValueType="int16", writeType="holdin$
    Thing data ventolaImmissione01 @"VMC" [ readStart="1", readValueType="int16", writeStart="1", writeValueType="int16", writeType="holdin$
    Thing data gestioneVentilazione02 @"VMC" [ readStart="2", readValueType="int16"]
    Thing data deumidificatore03 @"VMC" [ readStart="3", readValueType="int16", writeStart="3", writeValueType="int16", writeType="holding"]
    Thing data integrazione04 @"VMC" [ readStart="4", readValueType="int16", writeStart="4", writeValueType="int16", writeType="holding"]
    Thing data ricircolo05 @"VMC" [ readStart="5", readValueType="int16", writeStart="5", writeValueType="int16", writeType="holding"]
    Thing data modalitaAttiva06 @"VMC" [ readStart="6", readValueType="int16", writeStart="6", writeValueType="int16", writeType="holding"]
    Thing data gestioneEstateInverno07 @"VMC" [ readStart="7", readValueType="int16", writeStart="7", writeValueType="int16", writeType="ho$
    Thing data estateInverno08 @"VMC" [ readStart="8", readValueType="int16", writeStart="8", writeValueType="int16", writeType="holding"]
   Thing data attivaFasceOrarie09 @"VMC" [ readStart="9", readValueType="int16"]
   Thing data allarmeAttivo10 @"VMC" [ readStart="10", readValueType="int16"]
   Thing data resetAllarmiModus11 @"VMC" [ readStart="11", readValueType="int16", writeStart="11", writeValueType="int16", writeType="hold$
   Thing data codiceEvento12 @"VMC" [ readStart="12", readValueType="int16"]
   Thing data numeroEventoLow13 @"VMC" [ readStart="13", readValueType="int16"]
   Thing data numeroEventoHigh14 @"VMC" [ readStart="14", readValueType="int16"]
   Thing data oraEventoLow15 @"VMC" [ readStart="15", readValueType="int16"]
}
}

Randomly I am getting these errors I guess related to the poller and some wrong settings:

2020-07-17 16:21:18.076 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing 
modbus:poller:riscVmc:holdings0015 received error 
ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: 
EOFException null', cause2=null) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@c33eb9[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=16,maxTries=3]

2020-07-17 16:21:18.081 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing 
modbus:data:riscVmc:holdings0015:ventolaEspulsione00 'Modbus Data' had ModbusSlaveIOExceptionImpl error on read: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null)

2020-07-17 16:21:18.087 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing 
modbus:data:riscVmc:holdings0015:ventolaImmissione01 'Modbus Data' had ModbusSlaveIOExceptionImpl error on read: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null)

2020-07-17 16:21:18.088 [hingStatusInfoChangedEvent] - 'modbus:data:riscVmc:holdings0015:ventolaEspulsione00' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error (ModbusSlaveIOExceptionImpl) with read. Request: ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@c33eb9[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=16,maxTries=3]. Description: ModbusSlaveIOException(cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null). Message: Modbus IO Error with cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null

Can anyone help spotting what is wrong here?
Thanks

It doesn’t look like the usual timeout associated with a non-responsive slave.
Looks more like TCP fragmentation or something.

What’s the error rate? Does it always recover on the retry?

Hi @rossko57, thank you for your prompt answer!

I’ve tried to look at the occurrence of the error on one poller only but it looks pretty randon to me…

2020-07-17 16:54:21.449 [hingStatusInfoChangedEvent] - 'modbus:poller:riscVmc:holdings1631' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error with read: org.openhab.io.transport.modbus.internal.ModbusSlaveIOExceptionImpl: Modbus IO Error with cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null

2020-07-17 16:54:34.416 [hingStatusInfoChangedEvent] - 'modbus:poller:riscVmc:holdings1631' changed from OFFLINE (COMMUNICATION_ERROR): Error with read: org.openhab.io.transport.modbus.internal.ModbusSlaveIOExceptionImpl: Modbus IO Error with cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null to ONLINE

2020-07-17 16:55:30.161 [hingStatusInfoChangedEvent] - 'modbus:poller:riscVmc:holdings1631' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error with read: org.openhab.io.transport.modbus.internal.ModbusSlaveIOExceptionImpl: Modbus IO Error with cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null

2020-07-17 16:55:34.912 [hingStatusInfoChangedEvent] - 'modbus:poller:riscVmc:holdings1631' changed from OFFLINE (COMMUNICATION_ERROR): Error with read: org.openhab.io.transport.modbus.internal.ModbusSlaveIOExceptionImpl: Modbus IO Error with cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null to ONLINE

2020-07-17 16:56:05.543 [hingStatusInfoChangedEvent] - 'modbus:poller:riscVmc:holdings1631' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Error with read: org.openhab.io.transport.modbus.internal.ModbusSlaveIOExceptionImpl: Modbus IO Error with cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null

2020-07-17 16:56:10.208 [hingStatusInfoChangedEvent] - 'modbus:poller:riscVmc:holdings1631' changed from OFFLINE (COMMUNICATION_ERROR): Error with read: org.openhab.io.transport.modbus.internal.ModbusSlaveIOExceptionImpl: Modbus IO Error with cause=ModbusIOException, EOF=false, message='I/O exception: EOFException null', cause2=null to ONLINE 

It always recover on the retry on every object.

Can you please clarify what you mean with TCP fragmentation?

Additional logs below:

2020-07-17 23:37:41.690 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: EOFException null. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@a0da7f (unit id 1 & transaction 427). Address: /192.168.0.17:8899


2020-07-17 23:37:43.087 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: EOFException null. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@1581fc2 (unit id 1 & transaction 429). Address: /192.168.0.17:8899

2020-07-17 23:37:43.089 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: EOFException null. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@1581fc2 (unit id 1 & transaction 429). Address: /192.168.0.17:8899

2020-07-17 23:37:43.092 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Last try 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@34ebb2[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=16,length=16,maxTries=3]). Aborting. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: EOFException null [operation ID b0f850ca-f376-4dee-b599-b9a12e5e6617]

2020-07-17 23:37:41.692 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: EOFException null. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@a0da7f (unit id 1 & transaction 427). Address: /192.168.0.17:8899

That’s about TCP messages getting split across more than one packet. I think now it’s unlikely, and in any case the binding should handle it. (as for the mystery slave, who knows, but it’s really unlikely to get the smaller poll message in fragments)

message='I/O exception: EOFException null'

A bit of googly about that in other contexts suggests it may be about the remote end closing TCP connection unexpectedly.
Your modbus TCP is all default parameters, which mostly works for most devices, but can sometimes need tweaking.
I would recommend you change to keep the connection open, to reduce the open/close churn at your slave. It might just be slow dealing with previous disconnects. And/or a little time between reconnects may help.
See -

Hi @rossko57, thanks for your tips.

I’ve tried to apply reconnectAfterMillis and timeoutBetweenREconnectMillis settings but the timeout errors got even worse.

I believe I may have set something wrong on my USR-W610 device.

Do you have some suggestions on good Modbus TCP settings to be well compatible with the OpenHab Modbus Binding?

It’s weird because all Data Items from holding1 Poller works fine as soon as I add another poller (because I cannot go over max lenght 16) everything started to break.

It seems like my config is not working with multiple pollers anymore for some reason…

Bridge modbus:tcp:riscVmc [ host="192.168.0.17", port=8899, id=1, connectMaxTries=3, reconnectAfterMillis=60000, timeBetweenReconnectMillis=1000 ] {

  Bridge poller holdings1 [ start=0, length=16, refresh=5000, maxEntries=2, type="holding" ] {
    Thing data ventolaEspulsione00 @"VMC" [ readStart="0", readValueType="int16", writeStart="0", writeValueType="int16", writeType="holding"]
    Thing data ventolaImmissione01 @"VMC" [ readStart="1", readValueType="int16", writeStart="1", writeValueType="int16", writeType="holding"]
    Thing data gestioneVentilazione02 @"VMC" [ readStart="2", readValueType="int16"]
    Thing data deumidificatore03 @"VMC" [ readStart="3", readValueType="int16", writeStart="3", writeValueType="int16", writeType="holding"]
    Thing data integrazione04 @"VMC" [ readStart="4", readValueType="int16", writeStart="4", writeValueType="int16", writeType="holding"]
    Thing data ricircolo05 @"VMC" [ readStart="5", readValueType="int16", writeStart="5", writeValueType="int16", writeType="holding"]
    Thing data modalitaAttiva06 @"VMC" [ readStart="6", readValueType="int16", writeStart="6", writeValueType="int16", writeType="holding"]
    Thing data gestioneEstateInverno07 @"VMC" [ readStart="7", readValueType="int16", writeStart="7", writeValueType="int16", writeType="holding"]
    Thing data estateInverno08 @"VMC" [ readStart="8", readValueType="int16", writeStart="8", writeValueType="int16", writeType="holding"]
    Thing data attivaFasceOrarie09 @"VMC" [ readStart="9", readValueType="int16"]
    Thing data allarmeAttivo10 @"VMC" [ readStart="10", readValueType="int16"]
    Thing data resetAllarmi11 @"VMC" [ readStart="11", readValueType="int16", writeStart="11", writeValueType="int16", writeType="holding"]
    Thing data codiceEvento12 @"VMC" [ readStart="12", readValueType="int16"]
    Thing data numeroEventoLow13 @"VMC" [ readStart="13", readValueType="int16"]
    Thing data numeroEventoHigh14 @"VMC" [ readStart="14", readValueType="int16"]
    Thing data oraEventoLow15 @"VMC" [ readStart="15", readValueType="int16"]
  }

  Bridge poller holdings2 [ start=16, length=16, refresh=5000, maxEntries=2, type="holding" ] {
    Thing data oraEventoHigh16 @"VMC" [ readStart="16", readValueType="int16"]
    Thing data vediUltimoEvento17 @"VMC" [ readStart="17", readValueType="int16"]
    Thing data vediEventoPrecedente18 @"VMC" [ readStart="18", readValueType="int16"]
    Thing data vediEventoSuccessivo19 @"VMC" [ readStart="19", readValueType="int16"]
    Thing data contaoreFiltriLow20 @"VMC" [ readStart="20", readValueType="int16"]
    Thing data contaoreFiltriHigh21 @"VMC" [ readStart="21", readValueType="int16"]
    Thing data contaoreTotaliLow22 @"VMC" [ readStart="22", readValueType="int16"]
    Thing data contaoreTotaliHigh23 @"VMC" [ readStart="23", readValueType="int16"]
    Thing data resetFiltriModBus24 @"VMC" [ readStart="24", readValueType="int16"]
    Thing data temperaturaMandata25 @"VMC" [ readStart="25", readValueType="int16", readTransform="JS(divide10.js)" ]
    Thing data temperaturaRinnovo26 @"VMC" [ readStart="26", readValueType="int16", readTransform="JS(divide10.js)" ]
    Thing data temperaturaRipresa27 @"VMC" [ readStart="27", readValueType="int16", readTransform="JS(divide10.js)" ]
    Thing data temperaturaAcquaInEntrata28 @"VMC" [ readStart="28", readValueType="int16", readTransform="JS(divide10.js)" ]
    Thing data temperaturaCondensatore29 @"VMC" [ readStart="29", readValueType="int16", readTransform="JS(divide10.js)" ]
    Thing data temperaturaEvaporatore30 @"VMC" [ readStart="30", readValueType="int16", readTransform="JS(divide10.js)" ]
    Thing data temperaturaAmbiente31 @"VMC" [ readStart="31", readValueType="int16", readTransform="JS(divide10.js)" ]
  }
}

If I add the holdings2 poller I get this error:

2020-08-08 17:45:56.945 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandler.ModbusPollerReadRequest@1ac02e0[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=16,length=16,maxTries=3]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: EOFException null [operation ID f7713549-ec32-4e90-a619-95f43f234647]

2020-08-08 17:45:56.956 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Error invalidating connection in pool for endpoint ModbusTCPSlaveEndpoint@1f931ed[address=192.168.0.17,port=8899]. Error was: java.lang.NullPointerException null

java.lang.NullPointerException: null

	at java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936) ~[?:1.8.0_265]

	at org.openhab.io.transport.modbus.internal.pooling.ModbusSlaveConnectionFactoryImpl$PooledConnection.maybeResetConnection(ModbusSlaveConnectionFactoryImpl.java:87) ~[?:?]

	at org.openhab.io.transport.modbus.internal.pooling.ModbusSlaveConnectionFactoryImpl.passivateObject(ModbusSlaveConnectionFactoryImpl.java:223) ~[?:?]

	at org.openhab.io.transport.modbus.internal.pooling.ModbusSlaveConnectionFactoryImpl.passivateObject(ModbusSlaveConnectionFactoryImpl.java:1) ~[?:?]

	at org.apache.commons.pool2.impl.GenericKeyedObjectPool.addIdleObject(GenericKeyedObjectPool.java:1272) ~[?:?]

	at org.apache.commons.pool2.impl.GenericKeyedObjectPool.addObject(GenericKeyedObjectPool.java:1255) ~[?:?]

	at org.apache.commons.pool2.impl.GenericKeyedObjectPool.invalidateObject(GenericKeyedObjectPool.java:589) ~[?:?]

	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$1(ModbusManagerImpl.java:407) ~[?:?]

	at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_265]

	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.invalidate(ModbusManagerImpl.java:405) ~[?:?]

	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$9(ModbusManagerImpl.java:642) ~[?:?]

	at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeConsumer(SimpleStopWatch.java:169) ~[?:?]

	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:642) ~[?:?]

	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.access$2(ModbusManagerImpl.java:525) ~[?:?]

	at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$ModbusCommunicationInterfaceImpl.lambda$0(ModbusManagerImpl.java:755) ~[?:?]

	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_265]

	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_265]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_265]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_265]

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_265]

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_265]

	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]

What are we talking to here, a USR-W610? Over WiFi? What’s that talking to? Seems to be some RS232 device?

Let’s be clear about what you are trying to achieve here.
You want to use theW610 as a Modbus Gateway? This means that openHAB would talk Modbus-TCP to the W610, which automatically translates to Modbus-RTU on one of the serial ports.
You’d want to review the W610 user manual about “work mode”.

This topic was automatically closed 41 days after the last reply. New replies are no longer allowed.