Read time out error

Add-ons Bindings
1

Dear all, dear Miika Jukka

Thanks for the hint in the thread “modbus openHAb2 binding available for alpha testing”:

Miika Jukka wrote:

It’s a timeout error as you propably can see. Check all your connection parameters and make sure you server is up and running. You can use some 3rd party modbus tool to do this test.
After all that if you still got problems I would suggest you to open a new thread with much more detailed info about your configuration. This binding is now considered stable and this thread was more about testing and developing.

However I still get this error sproadically (i.e. every few hours), after which connection is reseted and restarted (see below):

16:39:54.447 [ERROR] [.wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@6b002a (unit id 1 & transaction 3646). Address: /192.168.178.30:502
16:39:54.461 [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.ReadMultipleRegistersRequest@6b002a (unit id 1 & transaction 3646). Address: /192.168.178.30:502

I tried to play around with the parameters (i.e. Poll Timeout set to 2000 ms and baud rate set to 115.2 kbps) of the modbus server, which is a usr iot 410s device (USR-TCP232-410S):

IMG_0160
IMG_01601328×1218 344 KB

The thing configuration is as follows:

Bridge modbus:tcp:Pool [ host="192.168.178.30", port=502, id=1 ] {
	Bridge poller holding_low [ start=0, length=24, refresh=500, type="holding"]{
       	Thing data holding0 [ readStart="0", readValueType="uint16", writeStart="0", writeValueType="uint16", writeType="holding" ]
       	Thing data holding1 [ readStart="1", readValueType="int16", readTransform="JS(divide10.js)", writeStart="1", writeValueType="int16", writeType="holding", writeTransform="JS(multiply10.js)" ]
    	Thing data holding6 [ readStart="6", readValueType="int16", readTransform="JS(divide10.js)" ]
    	Thing data holding7 [ readStart="7", readValueType="uint16", readTransform="JS(divide10.js)" ]
    	Thing data holding23 [ readStart="23", readValueType="int16" ]
    }
}

and the divice connected to the usr iot 410s is a peter vdi075 variable speed drive.

Could anyone help me in this- I would highly appreciate it. I have absolutely no idea where I should further search.

Best regards
Rolf

2

So you have a working connection but it gets a timeout every few hours? If so, you could try to raise your polling rate a bit. And looks like you have only one retry. I have always used 3. And is it only openHAB that is connecting to your device or is there some other also polling values?

One big help in debugging is to enable DEBUG logging for modbus and transport bindings. Or even TRACE.

P.S. If you want to tag someone in your post just use “@+username”. Like this @Logos.

3

@gitMiguel :wink:

Thank you again for the hints

  1. Yes, exactly!

  2. Increasing polling rate means to increase the poll timeout to even more than 2000 in the usr iot device?

  3. I forgot to write that I put the parameter “connectMaxTries” in the tcp thing already at 2. But it still seems that there is only one try. Is it the wrong parameter? Side mark: Openhab is the only device accessing the usr iot

  4. I will put the log to trace. Let’s see if there are further hints.

Thank you in advance for your help

Best regards
Rolf

4

  1. My initial thought was that you didn’t have any working connection at all. As it is only rare timeout errors then there should be no need for external test tools. Just focus on tweaking binding settings.

  2. When I wrote that you should increase your polling rate I meant to say decrease it :man_facepalming: . Not to poll so often. (Not a native english speker so sorry for any confusion). In your thing configurations bridge section change refresh value. Let’s say from 500 to 1000.

  3. It should work if configured right. Please try again.

5

@gitMiguel: I still get these errors from time to time:

2019-06-15 11:44:31.789 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@1bfd56f (unit id 1 & transaction 12312). Address: /192.168.178.30:502
2019-06-15 11:44:31.795 [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.ReadMultipleRegistersRequest@1bfd56f (unit id 1 & transaction 12312). Address: /192.168.178.30:502
2019-06-15 11:44:31.800 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7671a7[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=24,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 af67a88f-9371-4033-9835-2f1dd9794fa4]
```I have the refresh rate in the poller thing set to 3000. any other idea what I could tune in the config parameters?

Thank you in advance
Rolf
6

How often, now? Does it recover on the retry?
TCP messages do get lost, Modbus devices may sometimes not respond to queries, and in your case with a gateway serial data can get corrupted.
You may be trying to fix something beyond your control.

How long is the serial cable, is it twisted pair, is it terminated? This is probably the weakest link in the chain. I’d use a lower baud rate if your device is configurable; 9600 is plenty fast enough for most practical purposes. (slow serial = less likely to be affected by electrical interference)

7

@rossko57:

  • I would say roughly every 6 hours I have such an error
  • I would say yes it recovers, i.e. it is not permanently disconnected
  • serial cable is quite low ca 40 cm, twisted. terminated ? if you mean that shield is grounded then no

My tcp and poller thing are configured like that (sorry for that, it is quite some time since the last post, however the gateway is still configured like shown above):

Bridge modbus:tcp:Pool [ host="192.168.178.30", port=502, id=1, connectMaxTries=2, reconnectAfterMillis=60000] {
	Bridge poller holding_low [ start=0, length=24, refresh=3000, maxTries=2, type="holding"]
8

This is easy to find out by looking a little further down in the log, for Try 2 out of 3 ... messages.

“Terminated” on a RS485 bus means adding a resistor across the Tx/Rx wires. It damps signal reflections. Usually 120R value or so.
You can often “get away without it” on short wiring runs like yours, and it seems you mostly do get away without it.
On long runs, you’d have one at each end, but you’ll only need one really.
Many devices - your USR gateway included, I think? - have a terminator built in that you select in or out by moving a link on the PCB.

9

@rossko57:

  • As I can see in the log there is no try 2 and try 3 of the poller thing, so I guess it does not recover.
  • What is also strange is that in the TCP thing I have connectMaxTries=2 but it does not seem to try a second one (maybe that refers to your point?)

Regarding my other configuration settings, do they make sense to you?

10

@rossko57: regarding the link on the PCB: As I can see the USR gateway does not have one…(?)

11

This is only about retrying to make a TCP connection when the first attempt was bungled. i.e. it’s not about retries just because a read failed, that’s controlled by maxTries in the poller Thing (which you have set to 2)…

I think if try 2 of 2 was failing you would get an error; so, see no error, the retry worked ok. That’s to say, it’s a transient error.

If you have no terminator on your RS485 line I would recommend it.
If you are able to set the end device to a lower baud rate, I’d recommend that too. (Obviously change the gateway to match)

Gateways complicate fault finding; you can have a perfectly good openHAB ↔ gateway TCP connection, and a serial line gateway ↔ slave that fails horribly. The gateway cannot tell openHAB about that.

12

@rossko57: thank you a lot for your help. I will try

13

@rossko57: I have set baud rate to 9600 and now i get many more of those read errors (I.e. every 15 minutes compared to every 6-12 hours before) what do you think?

14

The fact that it made a difference tells you that you are poking in the right area.

RS485 lines can be picky about both termination and bias ; I believe the USR gateways incorporate bias resistors so you shouldn’t need to do anything about that.
Terminator still seems to be on your to-do list.

We should remember that at 9600 a serial transfer simply takes longer. Maybe the timeout settings in your gateway are too aggressive.

What you’d really like to do is see what the gateway logs, but I’m not sure that is possible.

15

@rossko57: thank you for the reply. I have the timeout at the USR gateway already at 2000 ms, the ConnectTimeoutMillis in the TCP thing at 1000 ms and the refresh rate in the poller thing at 3000 ms. Do you think i should make these even longer? BTW: so far i have not seen the possibility to log the USR gateway

16

The TCP timeouts have nothing to do with the serial side. This is what I meant about gateways being complicated. openHAB swaps some data with the gateway according to some settings. The gateway swaps data with your device according to completely different settings, and detects errors in a completely different way, and if errors are detected it doesn’t tell openHAB anything about them.

17

@rossko57: thanks a lot! I fully understand that. My only point is, that there may be some dependencies regarding timeouts, i.e. if i have on the serial side 2000ms and on the tcp side only 1000 that there could be some conflicts. Or is that fully independent?

Again thanks a lot for your insights…

18

Hello all,
have a SMA inverter and Modbus TCP connection. Get multiple read errors over the day at the 1st connection attempt. Have not been able to eliminate this by parameter variation. Does anybody have some hints what could be done?

I also get such messages, if i use the “Radzio! Modbus Master Simulator”. Thus it seems not to be a binding issue.

Error example:
2019-12-14 23:06:28.310 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@1d91011 (unit id 3 & transaction 49573). Address: /192.168.1.104:502
2019-12-14 23:06:28.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@1d91011 (unit id 3 & transaction 49573). Address: /192.168.1.104:502
2019-12-14 23:06:28.325 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@263fc6[slaveId=3,functionCode=READ_INPUT_REGISTERS,start=30977,length=10,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 ebb5aee5-1225-4e64-b0e8-ed71eacfb973]

Thanks and best regards,

Willi

19

If the SMA doesn’t want to talk on Modbus-TCP at that moment, there isn’t much you can do.

It might be SMA overhead due to TCP disconnect/reconnect each time. You can play with settings to increase connection duration, with a warning that can lock out other apps.
You might be competing for time on the SMA with other apps, e.g. your phone app or some cloud service.
It might just be “too bad”, and the best you can do is configure to recover and retry gracefully.