Problem with modbus binding with dynamic on/off

This is very good log, thank you.

It seems that the following happened

  1. binding encountered I/O error when trying to communicate with the device
  2. Binding tries to close and reopen the connection (serial port), before trying again
  3. When binding tries to close the serial port, exception is raised by the underlying java serial library

Most likely the serial port is left with unclean state, explaining “port in use” errors that follow.

Have to see if I can find anything that would explain step 3) above…

EDIT: Do you have log lines before the IllegalMonitorStateException?
EDIT2: It seems that nrjavaserial version in openHAB does not have the upstream bug fix for https://github.com/NeuronRobotics/nrjavaserial/commit/f010deeb3c0367f469be338f3edf8f6528322063 , explaining the exception. Will file an issue on this to openHAB fork of nrjavaserial https://github.com/openhab/nrjavaserial

This shows that logging needs to be improved, we not log the underlying error properly. Will fix this. EDIT: pushed fix https://github.com/openhab/openhab-addons/pull/7085

The use case is that I would like to completely power off a device with modbus when not in use to save energy. At the same time, I also to need to disable the modbus poller to avoid spamming the log.

Surprisingly, it seems that enable and disable of the poller seems to open and close the usb port. I can see that using the lsof command. I would have thought that was controlled by Modbus Serial Slave Thing which is always enabled in my setup now.

There is nothing related to this before that line in the log. It is the first event in the log after I disabled the poller.

Yes, the use case is understood. I was poking for the circumstance that resulted in the shown error log.

Okay, this is news; you disabled poller Thing(s) at that time.
So at this point the target device is powered up or not?

Disabling (one of) your poller Thing isn’t expected to immediately stop all comms attempts, I believe the next scheduled poll will still try (at least this is what I’ve seen in my error handling procedure).

Thinking on it … a Serial Thing cannot “own” a serial port … it’s a bus system, there may be several such Serial Things sharing the same port.
It is reasonable to only “grab” the resource when needed - for read poll or asynchronous write.

That brings up back to the root issue of what is holding the port “busy”.

Hi @ssalonen - thanks for your effort in this.
I was wondering why the enable and disable of the poller triggers open and close of the usb port. How is then controlled if there are more pollers on the same usb port? I have several devices on the same Modbus network with each there own Modbus id and poller intended to be controlled by one single usb adapter. They are not in openHAB yet, because I was waiting for my first device to work without errors.

I would expect that you would put the open close of the usb port to the Thing level, so it is controlled by the Modbus Serial Slave. It might not entirely solve the problem, as @rossko57 writes, but I guess it would reduce it.

My point was that you may have multiple Serial Bridge things sharing the same port. You’ll discover that when you configure more devices. So this “top level” bridge Thing cannot “own” the port since it needs to be shared with other Things.
I realise now that I was wrong, there is simply no one Thing in this binding that can take responsibility for managing the port. So it has to be a round robin, transaction based open-use-close.

Compare with Modbus-TCP, where we structure Things in the same hierarchy. This binding’s top level TCP Thing does not “own” the system ethernet port - and we wouldn’t want it to, everyone else wants network traffic too.

Don’t lose sight that the binding releasing the port is not a problem of itself … your problem is that it can’t get it back again. Sami’s chasing that down as a mess-up when closing it.

Question to @rossko57 and @ssalonen :

Would it make sense to open a usb port, if a poller needs it? - and never close it again. Then you would not need any advanced logic to figure out when to close a port, and no single object would own the port.
Also, it might solve the current issue we have.
You could argue that if you choose to put a usb port in a Thing file then openHAB will claim that port.

This is how it works actually.

Serial connection is opened on first modbus request, and kept open/initiliased till end of time. On I/O errors the binding tries to close and open the connection, but only in those situations. This is there to try to recover properly, very relevant with tcp connections at least.

With tcp connections user can define whether connection should be closed after each request, or after some time.

Disabling thing will not cause connection close itself (al

The IllegalMonitorStateException error discussed above is a bug in serial library used by openHAB. It will be fixed in 3.x. See Is nrjavaserial still maintained?

After thinking it through, the impact of the error is actually low and probably does not explain “port in use” errors"… I will still investigate this,however. If it does cause real problems, perhaps we can convince core developers to introduce new 2.5.x openhab with the bug fix.

Any further logs might help out to diagnose the issue further. It would help to use the snapshot version of the modbus transport bundle (org.openhab.io.transport.modbus) since that contains logging fix on “swallowed exceptions” (discussed above Problem with modbus binding with dynamic on/off).

EDIT:

There is nothing related to this before that line in the log. It is the first event in the log after I disabled the poller.

Checking the code I would still re-check this. There should be WARN line

"Try {} out of {} failed when executing request ({}). Will try again soon. Error was I/O error, so reseting the connection. Error details: {} {} [operation ID {}]",

or ERROR

"Last try {} failed when executing request ({}). Aborting. Error was I/O error, so reseting the connection. Error details: {} {} [operation ID {}]"

Would you please copy-paste lines preceding this log line?

2020-02-29 17:58:01.031 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Error invalidating connection in pool for endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]. Error was: java.lang.IllegalMonitorStateException null
java.lang.IllegalMonitorStateException: null

Hi

Here are the lines before, but I suspected that failure to be my own, because I was playing around with Modbus and I might switched + and - on RS485. That is why I wrote no errors before that. But the message you mention is present.

2020-02-29 17:57:57.791 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6bab2106[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,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 ed9a92de-7275-4473-bf17-aebb9e6ddc08]
2020-02-29 17:57:59.424 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 03 00 00 00 40 44 3a
2020-02-29 17:57:59.424 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2020-02-29 17:57:59.425 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/1 error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@6540f686 (unit id 1 & transaction 352). Serial parameters: SerialParameters@7c5dbfcb[portName=/dev/ttyUSB5,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=2,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-02-29 17:57:59.425 [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@6540f686 (unit id 1 & transaction 352). Serial parameters: SerialParameters@7c5dbfcb[portName=/dev/ttyUSB5,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=2,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-02-29 17:57:59.426 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6bab2106[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,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 ed9a92de-7275-4473-bf17-aebb9e6ddc08]
2020-02-29 17:57:59.829 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Unregistering regular poll task BasicPollTaskImpl@30a58586[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6bab2106[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,maxTries=3],endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@497c319a] (interrupting if necessary)
2020-02-29 17:57:59.830 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Poll task BasicPollTaskImpl@30a58586[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6bab2106[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,maxTries=3],endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@497c319a] canceled
2020-02-29 17:58:01.029 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - Last request: 01 03 00 00 00 40 44 3a
2020-02-29 17:58:01.030 [ERROR] [t.wimpi.modbus.io.ModbusRTUTransport] - failed to read: Error reading response (EOF)
2020-02-29 17:58:01.030 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/1 error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@3acceea1 (unit id 1 & transaction 353). Serial parameters: SerialParameters@7c5dbfcb[portName=/dev/ttyUSB5,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=2,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-02-29 17:58:01.030 [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@3acceea1 (unit id 1 & transaction 353). Serial parameters: SerialParameters@7c5dbfcb[portName=/dev/ttyUSB5,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=2,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-02-29 17:58:01.030 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Last try 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6bab2106[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,maxTries=3]). Aborting. 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 ed9a92de-7275-4473-bf17-aebb9e6ddc08]
2020-02-29 17:58:01.031 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Error invalidating connection in pool for endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]. Error was: java.lang.IllegalMonitorStateException null
java.lang.IllegalMonitorStateException: null

It is really interesting that it will try to keep the port open always, and only open/close in case of i/o error.

Then I guess my setup will always hit an i/o error, because I do a power off on the device ?

Also, I have yet not blocked for that the power outlet can be manually turned off in my smart house, and I have used this in my tests as well. This means that in some situations the power was turned off, before the poller was stopped. This is of course not the long term solution, but that might be the reason for the problems ??

The long term solution is:

openhab operation turn on: power on device, wait a few seconds, and enable poller
openhab operation turn off: disable poller, wait a few seconds, power off device

manual operation turn on: power on device using wall switch input, wait some seconds and then use remote control
manual operation turn off: turn off using remote control. My openhab rule will detect this and stop poller after some seconds, wait again and then power off device

An i/o error will only arise if you do i/o
i.e. if you disable pollers before you kill the device (and avoid doing writes to it) then no error will arise.
EDIT - there is an implication there that you can still write to Modbus even when polled disabled. That might be useful for your “off” process.

If/when you’ve got other devices on the same serial bus, they’ll carry on the same.

That’s just an “ordinary error”, no different from a comms glitch.
It’s not the cause of your problem. “Ordinary errors” are perfectly manageable and recoverable without you doing anything special at all, recovery is built in the binding.
The kind of thing my related error management post was about is reducing impact on survivors (and logs)

1 Like

Thank you. Can you for completeness sake also copy paste log lines following the IllegalMonitorStateException?

It is already is this thread. See post made 29. February at 6.05 pm.

I noted the PortInUse error yes. But was there anything in between? After the IllegalMonitorStateException but before port in use error?

Another thing : I note that you use Linux. Could you please tell which pc is it, and what OS specifically? This might help me to try to reproduce it myself

Sorry for pestering but since I have not been able to reproduce this with my “virtual” serial port I am a bit handicapped.

Hi

Thanks again for your support. I have this one below with rows before and after IllegalMonitorStateException - I hope this is fine.

2020-02-29 17:58:01.030 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/1 error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@3acceea1 (unit id 1 & transaction 353). Serial parameters: SerialParameters@7c5dbfcb[portName=/dev/ttyUSB5,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=2,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-02-29 17:58:01.030 [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@3acceea1 (unit id 1 & transaction 353). Serial parameters: SerialParameters@7c5dbfcb[portName=/dev/ttyUSB5,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=2,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-02-29 17:58:01.030 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Last try 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6bab2106[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,maxTries=3]). Aborting. 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 ed9a92de-7275-4473-bf17-aebb9e6ddc08]
2020-02-29 17:58:01.031 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Error invalidating connection in pool for endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]. Error was: java.lang.IllegalMonitorStateException null
java.lang.IllegalMonitorStateException: null
at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryRelease(ReentrantReadWriteLock.java:371) ~[?:1.8.0_242]
at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1261) ~[?:1.8.0_242]
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.unlock(ReentrantReadWriteLock.java:1131) ~[?:1.8.0_242]
at gnu.io.RXTXPort.close(RXTXPort.java:1101) ~[?:?]
at net.wimpi.modbus.io.ModbusSerialTransport.close(ModbusSerialTransport.java:97) ~[?:?]
at net.wimpi.modbus.io.ModbusRTUTransport.close(ModbusRTUTransport.java:202) ~[?:?]
at net.wimpi.modbus.net.SerialConnection.close(SerialConnection.java:262) ~[?:?]
at net.wimpi.modbus.net.SerialConnection.resetConnection(SerialConnection.java:331) ~[?:?]
at org.openhab.io.transport.modbus.internal.pooling.ModbusSlaveConnectionFactoryImpl.destroyObject(ModbusSlaveConnectionFactoryImpl.java:152) ~[?:?]
at org.openhab.io.transport.modbus.internal.pooling.ModbusSlaveConnectionFactoryImpl.destroyObject(ModbusSlaveConnectionFactoryImpl.java:1) ~[?:?]
at org.apache.commons.pool2.impl.GenericKeyedObjectPool.destroy(GenericKeyedObjectPool.java:1104) ~[?:?]

I am running Ubunto 19.10 on a Dell laptop Latitude model E5550. It is installed directly and not using any virtualization.
Please be aware I have now ordered a TCP based modbus device which I might switch to instead of the serial usb based connection.

Which one?

Please add more lines following the error, these are all related to the error still.

Once you see lines starting with timestamp, you know it is a new log message

Hi

I hope this is what you need:

2020-02-29 17:58:01.030 [ERROR] [pi.modbus.io.ModbusSerialTransaction] - execute try 1/1 error: I/O exception: IOException Error reading response (EOF). Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@3acceea1 (unit id 1 & transaction 353). Serial parameters: SerialParameters@7c5dbfcb[portName=/dev/ttyUSB5,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=2,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-02-29 17:58:01.030 [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@3acceea1 (unit id 1 & transaction 353). Serial parameters: SerialParameters@7c5dbfcb[portName=/dev/ttyUSB5,baudRate=9600,flowControlIn=none,flowControlOut=none,databits=8,stopbits=2,parity=none,encoding=rtu,echo=false,receiveTimeoutMillis=1500]
2020-02-29 17:58:01.030 [ERROR] [rt.modbus.internal.ModbusManagerImpl] - Last try 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6bab2106[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,maxTries=3]). Aborting. 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 ed9a92de-7275-4473-bf17-aebb9e6ddc08]
2020-02-29 17:58:01.031 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Error invalidating connection in pool for endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]. Error was: java.lang.IllegalMonitorStateException null
java.lang.IllegalMonitorStateException: null
at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryRelease(ReentrantReadWriteLock.java:371) ~[?:1.8.0_242]
at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1261) ~[?:1.8.0_242]
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.unlock(ReentrantReadWriteLock.java:1131) ~[?:1.8.0_242]
at gnu.io.RXTXPort.close(RXTXPort.java:1101) ~[?:?]
at net.wimpi.modbus.io.ModbusSerialTransport.close(ModbusSerialTransport.java:97) ~[?:?]
at net.wimpi.modbus.io.ModbusRTUTransport.close(ModbusRTUTransport.java:202) ~[?:?]
at net.wimpi.modbus.net.SerialConnection.close(SerialConnection.java:262) ~[?:?]
at net.wimpi.modbus.net.SerialConnection.resetConnection(SerialConnection.java:331) ~[?:?]
at org.openhab.io.transport.modbus.internal.pooling.ModbusSlaveConnectionFactoryImpl.destroyObject(ModbusSlaveConnectionFactoryImpl.java:152) ~[?:?]
at org.openhab.io.transport.modbus.internal.pooling.ModbusSlaveConnectionFactoryImpl.destroyObject(ModbusSlaveConnectionFactoryImpl.java:1) ~[?:?]
at org.apache.commons.pool2.impl.GenericKeyedObjectPool.destroy(GenericKeyedObjectPool.java:1104) ~[?:?]
at org.apache.commons.pool2.impl.GenericKeyedObjectPool.invalidateObject(GenericKeyedObjectPool.java:585) ~[?:?]
at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$1(ModbusManagerImpl.java:365) ~[?:?]
at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_242]
at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.invalidate(ModbusManagerImpl.java:363) ~[?:?]
at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$9(ModbusManagerImpl.java:609) ~[?:?]
at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeConsumer(SimpleStopWatch.java:169) ~[?:?]
at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:609) ~[?:?]
at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_242]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_242]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_242]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_242]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_242]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_242]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_242]
2020-02-29 18:01:29.846 [ERROR] [et.wimpi.modbus.net.SerialConnection] - open port failed: gnu.io.PortInUseException: Modbus Serial Master
2020-02-29 18:01:29.847 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/1 error: open port failed: Modbus Serial Master. Connection SerialConnection@7424e5d9[portName=/dev/ttyUSB5,port=]. Endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]
2020-02-29 18:01:29.848 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - re-connect reached max tries 1, throwing last error: open port failed: Modbus Serial Master. Connection SerialConnection@7424e5d9[portName=/dev/ttyUSB5,port=]. Endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]
2020-02-29 18:01:29.848 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@7424e5d9[portName=/dev/ttyUSB5,port=] for endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]: open port failed: Modbus Serial Master
2020-02-29 18:01:29.850 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Could not connect to endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5] – aborting request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@459a5207[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,maxTries=3] [operation ID 7a6fd2d4-b98f-49f2-8218-61cae05f3b32]
2020-02-29 18:01:29.851 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitmode ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.851 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitfanspeed ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.852 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitverticalvaneposition ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.853 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unittemperaturesetpoint ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.853 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitonoff ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.854 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unittemperaturereference ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.855 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1windowcontact ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.855 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1openwindowswitchofftimeout ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.856 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1outdoorintaketemperature ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.857 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1powerconsumptionslow ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.857 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1powerful ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:29.858 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1quiet ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.849 [ERROR] [et.wimpi.modbus.net.SerialConnection] - open port failed: gnu.io.PortInUseException: Modbus Serial Master
2020-02-29 18:01:59.850 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/1 error: open port failed: Modbus Serial Master. Connection SerialConnection@3f86ccea[portName=/dev/ttyUSB5,port=]. Endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]
2020-02-29 18:01:59.851 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - re-connect reached max tries 1, throwing last error: open port failed: Modbus Serial Master. Connection SerialConnection@3f86ccea[portName=/dev/ttyUSB5,port=]. Endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]
2020-02-29 18:01:59.851 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@3f86ccea[portName=/dev/ttyUSB5,port=] for endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]: open port failed: Modbus Serial Master
2020-02-29 18:01:59.852 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Could not connect to endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5] – aborting request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@459a5207[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,maxTries=3] [operation ID c0e81b43-f8b7-4a40-920b-d4dd0e3da12f]
2020-02-29 18:01:59.853 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitmode ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.854 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitfanspeed ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.855 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitverticalvaneposition ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.856 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unittemperaturesetpoint ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.856 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitonoff ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.857 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unittemperaturereference ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.858 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1windowcontact ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.858 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1openwindowswitchofftimeout ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.859 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1outdoorintaketemperature ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.860 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1powerconsumptionslow ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.860 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1powerful ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:01:59.861 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1quiet ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.852 [ERROR] [et.wimpi.modbus.net.SerialConnection] - open port failed: gnu.io.PortInUseException: Modbus Serial Master
2020-02-29 18:02:29.852 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/1 error: open port failed: Modbus Serial Master. Connection SerialConnection@1bc9d888[portName=/dev/ttyUSB5,port=]. Endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]
2020-02-29 18:02:29.853 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - re-connect reached max tries 1, throwing last error: open port failed: Modbus Serial Master. Connection SerialConnection@1bc9d888[portName=/dev/ttyUSB5,port=]. Endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]
2020-02-29 18:02:29.853 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@1bc9d888[portName=/dev/ttyUSB5,port=] for endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5]: open port failed: Modbus Serial Master
2020-02-29 18:02:29.854 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Could not connect to endpoint ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5] – aborting request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@459a5207[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=64,maxTries=3] [operation ID 5e1c4316-fcc9-41a6-b226-dbe32585e8a0]
2020-02-29 18:02:29.855 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitmode ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.856 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitfanspeed ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.856 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitverticalvaneposition ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.857 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unittemperaturesetpoint ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.857 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unitonoff ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.858 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1unittemperaturereference ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.858 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1windowcontact ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.859 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1openwindowswitchofftimeout ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.859 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1outdoorintaketemperature ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.860 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1powerconsumptionslow ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.860 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1powerful ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:29.861 [ERROR] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave01:holdingsREG:Thac1quiet ‘Modbus Data’ had ModbusConnectionException error on read: ModbusConnectionException(Error connecting to endpoint=ModbusSerialSlaveEndpoint@788895a5[portName=/dev/ttyUSB5])
2020-02-29 18:02:59.854 [ERROR] [et.wimpi.modbus.net.SerialConnection] - open port failed: gnu.io.PortInUseException: Modbus Serial Master
2020-02-29 18:02:59.855 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/1 error: open port failed: Modbus Serial Master. Connection SerialConnection@2ae0515f[portName=/dev/ttyUSB5,port

1 Like

First I ordered this one, but I could not make it work. It received the modbus queries, but did not send a response. I do not know why.

So now I have ordered this product, which seems to more settings you can adjust. I am waiting for it to arrive.

Depends how you configured the whole setup.

It’s a serial adaptor, it is not capable of acting as a Modbus gateway.
What’s the difference?

With a gateway, you send it Modbus-TCP and it handles the conversion to Modbus-RTU. Simples.

With a serial adaptor like that, you send it packets of serial data. You can’t use that directly with the Modbus binding, which has no idea how to put serial data into ethernet for your device.
You could use it with a piece of software at your host providing a virtual serial port, that software then does whatever it needs to send that to the adaptor, which of course passes to real serial line. That’s the VCOM software for Windows provided with that device. The OH binding would then talk Modbus-RTU to the virtual serial port.

That is capable of acting as a proper gateway (amongst other modes)