New modbus binding config problems

The Modbus binding docs give you info to gather more diagnostic information

The Modbus binding docs also refer you to the Serial binding section about port access

https://www.openhab.org/docs/administration/serial.html#linux

Thanks for your reply. With regards to permission, I am using udevadm to fix this as mentioned on this link.

By doing that I should fix permission issue and changing device names. And I am already using one usb port for RFXCOM binding (link) which works fine.

Therefore, I hope that that permissions is not the problem. If I execute

ls -la /dev

it shows these permissions:

crw-rw-rw- 1 openhab users 188, 0 Dec 4 07:30 ttyUSB0
crw-rw-rw- 1 openhab users 188, 1 Dec 4 17:40 ttyUSB1
lrwxrwxrwx 1 root root 7 Dec 3 19:34 ttyUSB5 -> ttyUSB1
lrwxrwxrwx 1 root root 7 Nov 28 22:19 ttyUSB6 -> ttyUSB0

where usb5 is redirected to usb1. usb1 is no longer only for root user as default, but for all users. I guess that should be fine. It is working fine for usb6/usb0 which is my RFXCOM device.

Then I enabled tracing in karaf konsole for these:
log:set TRACE org.openhab.binding.modbus
log:set TRACE org.openhab.io.transport.modbus
log:set TRACE net.wimpi.modbus
log:set TRACE t.wimpi.modbus.io.ModbusRTUTransport

and snippets of the result is:

2019-12-04 17:36:10.923 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID 8686ab99-c6c6-435c-82c6-c63595f6921a]
2019-12-04 17:36:10.923 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID 8686ab99-c6c6-435c-82c6-c63595f6921a]
2019-12-04 17:36:10.924 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept 0 [operation ID 8686ab99-c6c6-435c-82c6-c63595f6921a]
2019-12-04 17:36:10.924 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 01 03 00 01 00 02 [operation ID 8686ab99-c6c6-435c-82c6-c63595f6921a]
2019-12-04 17:36:10.925 [DEBUG] [t.wimpi.modbus.io.ModbusRTUTransport] - Sent: 01 03 00 01 00 02 95 cb
2019-12-04 17:36:12.427 [TRACE] [t.wimpi.modbus.io.ModbusRTUTransport] - Managed to read at least one byte
2019-12-04 17:36:12.428 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 03 00 01 00 02 95 cb
2019-12-04 17:36:12.428 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2019-12-04 17:36:12.429 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/1 error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@54f33629 (unit id 1 & transaction 257). Serial parameters: SerialParameters@7f92ccd0[portName=/dev/ttyUSB1,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2019-12-04 17:36:12.430 [ERROR] [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.ReadMultipleRegistersRequest@54f33629 (unit id 1 & transaction 257). Serial parameters: SerialParameters@7f92ccd0[portName=/dev/ttyUSB1,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=1,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2019-12-04 17:36:12.431 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@51133324[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1,length=2,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 8686ab99-c6c6-435c-82c6-c63595f6921a]
2019-12-04 17:36:12.431 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - destroyObject for connection SerialConnection@5a2900c6[portName=/dev/ttyUSB1,port=/dev/ttyUSB1] and endpoint ModbusSerialSlaveEndpoint@6e85bf26[portName=/dev/ttyUSB1] -> closing the connection
2019-12-04 17:36:12.516 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - invalidating connection for endpoint ModbusSerialSlaveEndpoint@6e85bf26[portName=/dev/ttyUSB1] took 85 ms
2019-12-04 17:36:12.517 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicPollTaskImpl@1411bfc2[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@51133324[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1,length=2,maxTries=3],endpoint=ModbusSerialSlaveEndpoint@6e85bf26[portName=/dev/ttyUSB1],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@a959ab48] (oneOff=false)! Waiting for connection. Idle connections for this endpoint: 0, and active 0 [operation ID 8686ab99-c6c6-435c-82c6-c63595f6921a]
2019-12-04 17:36:12.517 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Created connection SerialConnection@65b3ca93[portName=/dev/ttyUSB1,port=] for endpoint ModbusSerialSlaveEndpoint@6e85bf26[portName=/dev/ttyUSB1]
2019-12-04 17:36:12.518 [TRACE] [et.wimpi.modbus.net.SerialConnection] - Got Port Identifier
2019-12-04 17:36:12.525 [TRACE] [et.wimpi.modbus.net.SerialConnection] - Got Serial Port
2019-12-04 17:36:12.526 [TRACE] [et.wimpi.modbus.net.SerialConnection] - i/o Streams prepared
2019-12-04 17:36:12.527 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 0ms (interTransactionDelayMillis 200ms) before giving returning connection SerialConnection@65b3ca93[portName=/dev/ttyUSB1,port=/dev/ttyUSB1] for endpoint ModbusSerialSlaveEndpoint@6e85bf26[portName=/dev/ttyUSB1], to ensure delay between transactions.
2019-12-04 17:36:12.527 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[SerialConnection@65b3ca93[portName=/dev/ttyUSB1,port=/dev/ttyUSB1]]) for endpoint ModbusSerialSlaveEndpoint@6e85bf26[portName=/dev/ttyUSB1] took 10 ms
2019-12-04 17:36:12.528 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicPollTaskImpl@1411bfc2[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@51133324[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1,length=2,maxTries=3],endpoint=ModbusSerialSlaveEndpoint@6e85bf26[portName=/dev/ttyUSB1],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@a959ab48] (oneOff=false)! Connection received in 11 ms [operation ID 8686ab99-c6c6-435c-82c6-c63595f6921a]

From this trace above I am not able to identify root cause - unfortunately.

That seems to suggest it got hold of USB1, so that should rule out permission or contention problems.

Séems like a comms issue - is this over the same wire? I’m not sure if post 2.4 versions may have a bit more detail for serial tracing.

It seems I finally found out core reason. I am running openHAB on Synology NAS model DS218+. This model has 2 USB 3.0 ports on the back and 1 USB 3.0 port on the front.

For some unknown reason I cannot use both USB ports on the backside at the same time in openHAB. However, if I connect to one port on the back and one port on the front side, everything is working fine.

Thanks for your support.

Definitely file under “weird”.

1 Like