Checked the code of modbus rtu and indeed the CRC is NOT included in the log message.
Best
Sami
having now this config:
serial.slave1.connection=/dev/ttyUSB0:9600:8:none:1:rtu:350:500
item.conf:
Number Slave1LDR "Lichtmenge [%d]" (All) { modbus="slave1:1" }
Number Slave1Temp "Temperatur [%.1f °C]" (All) { channel="modbus:slave1:3" }
Number Slave1RH "Feuchtigkeit [%d]" (All) { channel="modbus:slave1:4" }
i got in my openhab.log this: I tried to trigger the modbus poll over sitemap. but the log doesn’t show up any conversation. Is the polling running?
2016-10-31 10:29:20.774 [DEBUG] [inding.modbus.internal.ModbusBinding] - modbusSlave 'slave1' instanciated
2016-10-31 10:29:20.783 [DEBUG] [inding.modbus.internal.ModbusBinding] - Parsed the following slave->endpoint configurations: {slave1=EndpointPoolConfiguration@3ef4c7[passivateBorrowMinMillis=350,interConnectDelayMillis=0,connectMaxTries=3,reconnectAfterMillis=-1,connectTimeoutMillis=0]}. If the endpoint is same, connections are shared between the instances.
2016-10-31 10:29:20.784 [DEBUG] [inding.modbus.internal.ModbusBinding] - Parsed the following pool configurations: {ModbusSerialSlaveEndpoint@84ee61[portName=/dev/ttyUSB0]=EndpointPoolConfiguration@3ef4c7[passivateBorrowMinMillis=350,interConnectDelayMillis=0,connectMaxTries=3,reconnectAfterMillis=-1,connectTimeoutMillis=0]}
2016-10-31 10:29:20.785 [DEBUG] [inding.modbus.internal.ModbusBinding] - config looked good
2016-10-31 10:29:20.788 [INFO ] [b.core.service.AbstractActiveService] - Modbus Polling Service has been started
2016-10-31 10:33:17.127 [DEBUG] [inding.modbus.internal.ModbusBinding] - modbusSlave 'slave1' instanciated
2016-10-31 10:33:17.132 [DEBUG] [inding.modbus.internal.ModbusBinding] - Parsed the following slave->endpoint configurations: {slave1=EndpointPoolConfiguration@838bcc[passivateBorrowMinMillis=350,interConnectDelayMillis=0,connectMaxTries=3,reconnectAfterMillis=-1,connectTimeoutMillis=0]}. If the endpoint is same, connections are shared between the instances.
2016-10-31 10:33:17.135 [DEBUG] [inding.modbus.internal.ModbusBinding] - Parsed the following pool configurations: {ModbusSerialSlaveEndpoint@11edc97[portName=/dev/ttyUSB0]=EndpointPoolConfiguration@838bcc[passivateBorrowMinMillis=350,interConnectDelayMillis=0,connectMaxTries=3,reconnectAfterMillis=-1,connectTimeoutMillis=0]}
2016-10-31 10:33:17.137 [DEBUG] [inding.modbus.internal.ModbusBinding] - config looked good
2016-10-31 10:35:10.422 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item 'Slave1Temp' for widget org.eclipse.smarthome.model.sitemap.Text
2016-10-31 10:35:10.429 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item for widget org.eclipse.smarthome.model.sitemap.Text
2016-10-31 10:35:10.431 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item for widget org.eclipse.smarthome.model.sitemap.Text
2016-10-31 10:35:10.433 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item 'Slave1Temp' for widget org.eclipse.smarthome.model.sitemap.Text
2016-10-31 10:35:10.438 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item 'Slave1Temp' for widget org.eclipse.smarthome.model.sitemap.Text
2016-10-31 10:35:10.443 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item 'Slave1RH' for widget org.eclipse.smarthome.model.sitemap.Text
and later the missing EOF starts again (:350:500):
2016-10-31 11:29:44.797 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 03 00 00 00 05 85 c9
2016-10-31 11:29:44.798 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2016-10-31 11:29:44.800 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 3/3 error: I/O exception - failed to read. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@ea61c (unit id 1 & transaction 2774). Serial parameters: SerialParameters@8eb2d3[portName=/dev/ttyUSB0,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=500]
2016-10-31 11:29:44.801 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute reached max tries 3, throwing last error: I/O exception - failed to read. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@ea61c. Serial parameters: SerialParameters@8eb2d3[portName=/dev/ttyUSB0,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=500]
2016-10-31 11:29:44.803 [ERROR] [.binding.modbus.internal.ModbusSlave] - ModbusSlave (slave1): Error getting modbus data for request net.wimpi.modbus.msg.ReadMultipleRegistersRequest@ea61c. Error: I/O exception - failed to read. Endpoint ModbusSerialSlaveEndpoint@349618[portName=/dev/ttyUSB0]. Connection: SerialConnection@963c65[portName=/dev/ttyUSB0,port=/dev/ttyUSB0]
serial.slave1.connection=/dev/ttyUSB0:9600:8:none:1:rtu:350:1500
still reading issues:
2016-10-31 11:48:55.507 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 03 00 00 00 05 85 c9
2016-10-31 11:48:55.508 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: CRC Error in received frame: 12 bytes: 01 03 0a 00 00 00 00 00 08 70 13 d8
2016-10-31 11:48:55.509 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/3 error: I/O exception - failed to read. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@104586d (unit id 1 & transaction 123). Serial parameters: SerialParameters@11a356[portName=/dev/ttyUSB0,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
and with 500:2500 openhab.log loocks like after a restart (remakr 13min timout bevore EOF issues rises!):
2016-10-31 12:11:23.319 [DEBUG] [ding.modbus.internal.ModbusActivator] - Modbus binding has been started.
2016-10-31 12:11:23.345 [DEBUG] [org.openhab.binding.modbus ] - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.modbus.ModbusBindingProvider}={component.name=org.openhab.binding.modbus.genericbindingprovider, component.id=183, service.id=314, service.bundleid=200, service.scope=bundle} - org.openhab.binding.modbus
2016-10-31 12:11:23.349 [DEBUG] [org.openhab.binding.modbus ] - ServiceEvent REGISTERED - {org.osgi.service.cm.ManagedService, org.osgi.service.event.EventHandler}={event.topics=openhab/*, service.pid=org.openhab.modbus, component.name=org.openhab.binding.modbus, component.id=182, service.id=316, service.bundleid=200, service.scope=bundle} - org.openhab.binding.modbus
2016-10-31 12:11:23.407 [DEBUG] [org.openhab.binding.modbus ] - BundleEvent STARTED - org.openhab.binding.modbus
2016-10-31 12:11:23.503 [DEBUG] [inding.modbus.internal.ModbusBinding] - modbusSlave 'slave1' instanciated
2016-10-31 12:11:23.583 [DEBUG] [inding.modbus.internal.ModbusBinding] - Parsed the following slave->endpoint configurations: {slave1=EndpointPoolConfiguration@1a22d36[passivateBorrowMinMillis=500,interConnectDelayMillis=0,connectMaxTries=3,reconnectAfterMillis=-1,connectTimeoutMillis=0]}. If the endpoint is same, connections are shared between the instances.
2016-10-31 12:11:23.584 [DEBUG] [inding.modbus.internal.ModbusBinding] - Parsed the following pool configurations: {ModbusSerialSlaveEndpoint@156fb8a[portName=/dev/ttyUSB0]=EndpointPoolConfiguration@1a22d36[passivateBorrowMinMillis=500,interConnectDelayMillis=0,connectMaxTries=3,reconnectAfterMillis=-1,connectTimeoutMillis=0]}
2016-10-31 12:11:23.586 [DEBUG] [inding.modbus.internal.ModbusBinding] - config looked good
2016-10-31 12:11:23.588 [INFO ] [b.core.service.AbstractActiveService] - Modbus Polling Service has been started
2016-10-31 12:11:24.990 [ERROR] [platform.linux.LinuxCentralProcessor] - Couldn't find physical processor count. Assuming 1.
2016-10-31 12:11:25.418 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro DailyJob at midnight for thing astro:sun:local
2016-10-31 12:11:25.438 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro DailyJob at midnight for thing astro:moon:local
2016-10-31 12:11:25.440 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro PositionalJob with interval of 300 seconds for thing astro:sun:local
2016-10-31 12:11:25.444 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro PositionalJob with interval of 300 seconds for thing astro:moon:local
2016-10-31 12:11:26.045 [ERROR] [platform.linux.LinuxCentralProcessor] - Unable to parse /proc/76/stat
2016-10-31 12:26:17.409 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 03 00 00 00 05 85 c9
2016-10-31 12:26:17.410 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2016-10-31 12:26:17.412 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/3 error: I/O exception - failed to read. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@1e1eff5 (unit id 1 & transaction 856). Serial parameters: SerialParameters@488384[portName=/dev/ttyUSB0,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=2500]
2016-10-31 12:26:20.428 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 03 00 00 00 05 85 c9
2016-10-31 12:26:20.430 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
Did you notice the errors related to sitemap (ItemUIRegistryImpl)? I think that might be unrelated to the modbus IO issues…
Unfortunately I’m not too familiar with openhab2 to comment those.
I also noticed you have varying way of configuring the binding in the items (channel and modbus parameter)
I’m running out of advice to workaround the EOF issue. If the serial parameters (e.g. Baud or Stop bit) would be off, I would expect it to fail much more, not after 15min. I noticed that you cut the logs before all retries have been tried out, did it work eventually?
Oh one more thing, could please provide the full details about the modbus configuration, really hard to debug with limited information. I was wondering how many registers you are now reading and whether the read timeout is sufficient…
From the technical perspective I’m not sure what the binding should do as the EOF comes from the serial library bundled by openhab (nrjavaserial I believe). I hope it is the same library in openhab2, but not sure.
Best
Sami
After hours of reading log-files, this is what’s running:
items: on top of the file… yes… yeah!
Number Slave1LDR "Lichtmenge [%d]" { modbus="slave1:0" }
Number Slave1Temp "Temperatur [%.1f °C]" { modbus="slave1:1" }
Number Slave1RH "Feuchtigkeit [%d]" { modbus="slave1:2" }
service:
poll=3000
serial.slave1.connection=/dev/ttyUSB0:19200:8:none:1:rtu
serial.slave1.id=1
serial.slave1.start=0
serial.slave1.length=5
serial.slave1.type=holding
serial.slave1.valuetype=int16
Thanks for any help. I will finally start over with feature implementation…
For future records,
I believe the issue was that the default read timeout (1.5s) might have been too little for 9600 baud. Since you increased the baud rate, it was sufficient after all. Let’s see if this issue occurs again and if the default need changing. Actually, with little arithmetic we could probably calculate the time it might take to send a single modbus frame in total.
Concerning different baud-rates for the same modbus serial line, mentioned from @carzten2000 (see above) and the fact that
I think it would be helpfull to mention the fact, that it’s kind of ‘bad practice’, in the binding description (wiki, openhab.cfg, …?). Additionally an error during config-parsing would be nice.
Is there already an information somewhere, am I missing something?
Best
That is general information for any Modbus serial device, most likely mentioned in the device’s documentation and also in general guides to Modbus.
So is history education and yet you know nothing John Snow. 
There is a hint in the wiki which says “Please note that the binding requires that all slaves connecting to the same serial port share the same connection parameters. For additional information, see this discussion in the community forums”. But to get there you have to ensure that everything is correct with your modbus connection itself and the set-up parameters, to finally turn on trace level debugging and find out that there’s an issue with the baudrate.
a) Error message during config parsing
b) a little more information in the wiki
Hi
I believe error message is logged with WARN level. Not a critical error and thus the binding continues (later configurations override previous ones)
Feel free to improve the wiki please, contributions are more than welcome!
Best
Sami
EDIT: correction: WARN is logged only if the retry count / delay between connections is different. The 1.9.0 binding does not re-estabilish / initiate the connection parameters; first time the stop bits etc. have been setup for serial device/serial port, they remain unchanged. So in a way the first poll inits the devices.
Hi
I’ve recently restored my old modbus setup which was successfully working with OH1.8
Currently I have only 2 devices - SDM120 meter and WP8027ADAM (16x Digital Out).
After reading all the discussions I’ve played a bit with the timers but still have occasional errors in the log.
Will appreciate all the recommendations.
Here is my modbus.cfg:
poll=1000
serial.slave1.connection=/dev/ttyUSB1:9600:8:none:1:rtu:100:5000
serial.slave1.id=1
serial.slave1.start=0
serial.slave1.length=2
serial.slave1.type=input
serial.slave1.valuetype=float32
serial.slave2.connection=/dev/ttyUSB1:9600:8:none:1:rtu:100:5000
serial.slave2.id=1
serial.slave2.start=6
serial.slave2.length=2
serial.slave2.type=input
serial.slave2.valuetype=float32
serial.slave3.connection=/dev/ttyUSB1:9600:8:none:1:rtu:100:5000
serial.slave3.id=1
serial.slave3.start=12
serial.slave3.length=2
serial.slave3.type=input
serial.slave3.valuetype=float32
serial.slave20.connection=/dev/ttyUSB1:9600:8:none:1:rtu
serial.slave20.id=2
serial.slave20.start=0
serial.slave20.length=4
serial.slave20.type=coil
And here is the log:
2017-04-08 11:38:41.404 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 04 00 06 00 02 91 ca
2017-04-08 11:38:41.405 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2017-04-08 11:38:41.410 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/3 error: I/O exception - failed to read. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@3564c11b (unit id 1 & transaction 6612). Serial parameters: SerialParameters@7d8473ea[portName=/dev/ttyUSB1,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=5000]
2017-04-08 11:38:41.569 [INFO ] [pi.modbus.io.ModbusSerialTransaction] - execute eventually succeeded with 1 re-tries. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@3564c11b. Serial parameters: SerialParameters@7d8473ea[portName=/dev/ttyUSB1,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=5000]
Hi!
First of all note this comment on docs
Please note that the binding requires that all slaves connecting to the same serial port share the same connection parameters (e.g. baud-rate, parity, …). In particular are different parameter settings considered bad practice, because they can confuse the instances (slaves) on the modbus. For additional information, see this discussion in the community forums.
Currently one of “slaves” have different connection parameters.
Also this might be useful for you (from docs)
Most important of these is the interTransactionDelayMillis which ensures that Modbus RTU (serial) has enough “silent time” between the transactions, as required by the Modbus/RTU protocol. Furthermore it ensures that modbus slave (applies to both tcp and serial slaves) is not spammed with too many transactions, for example some PLC devices might not be able to handle many requests coming in a short time window.
You might want to try out to change that parameter.
Please also note that it eventually succeeded with the read. Do you have cases where it cannot read even after retries?
Best
Sami
Noted and fixed already.
Yes, I noticed that as well from the previous discussion.
I’m testing now with 350 instead of 100 but wandering what would be the best range for either value to test within?
It was probably the case initially when I started with default parameters. I don’t see this anymore.
Thanks!
350ms sounds like a conservative upper bound. I would say values over 1000ms make no sense.
Best
Sami
I’ve made some test over weekend and it seems that “350:3000” will be the safe choice.
I’m curious how it was working in OH1 without adjustments.
Thanks, Sami!
The underlying serial library used by openHAB (by all the bindings communicating with serial devices) has received update some time ago, perhaps that is the reason.
Good thing it works for you.
Best
Sami
I’ve tried to read 4 registers at once instead of 2 - same EOF errors every 1-2 hours 
But does it work after the automatic retry?
Best
Sami
Yes, it works after retry:
2017-04-12 11:17:10.826 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 04 00 0c 00 02 b1 c8
2017-04-12 11:17:10.826 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2017-04-12 11:17:10.829 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/3 error: I/O exception - failed to read. Requ
est: net.wimpi.modbus.msg.ReadInputRegistersRequest@5f2ce543 (unit id 1 & transaction 1741). Serial parameters: SerialParameters@534
0aaa0[portName=/dev/ttyUSB1,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo
=false,receiveTimeoutMillis=3000]
2017-04-12 11:17:11.232 [INFO ] [pi.modbus.io.ModbusSerialTransaction] - execute eventually succeeded with 1 re-tries. Request: net.
wimpi.modbus.msg.ReadInputRegistersRequest@5f2ce543. Serial parameters: SerialParameters@5340aaa0[portName=/dev/ttyUSB1,baudRate=960
0,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=3000]
It could be noise on your serial line, maybe not helped by poor termination or pullups etc.