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.