Modbus binding loses its serial connection every few days without a reason after updating to 2.5.0 Release Build

The OH core reference to nrjavaserial is here and the release file from the website contains only the 5.2.1 JAR: openhab-3.0.0.M2.zip\runtime\system\com\neuronrobotics\nrjavaserial\5.2.1\nrjavaserial-5.2.1.jar.

The error is the following:

[ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@1bffe68[portName=/dev/rs485-stick,port=<null>] for endpoint ModbusSerialSlaveEndpoint@f68504[portName=/dev/rs485-stick]: Could not get port identifier, maybe insufficient permissions. null

Unfortunately, the error came back last night.

I observed a deadlock after fiddling around with the serial ports in the modbus serial slave Thing configuration. The binding doesn’t seem to do anything, then. When disabling the Thing, the following message appears:

[WARN ] [rt.modbus.internal.ModbusManagerImpl] - Error getting a new connection for endpoint ModbusSerialSlaveEndpoint@365cd3[portName=/dev/rs485-stick]. Error was: java.lang.InterruptedException null

If I see correctly this happens only if the serial port cannot be retrieved from the connection pool: https://github.com/openhab/openhab-addons/blob/main/bundles/org.openhab.io.transport.modbus/src/main/java/org/openhab/io/transport/modbus/internal/ModbusManagerImpl.java#L380

Maybe this is only a subsequent error, but it might be worth to dig into it.

When the error occurred, I noticed the following message on stdout:

initialise_event_info_struct: initialise failed!

This is a known bug in nrjavaserial:

I applied the suggested fix to disable locking in the native libraries and it seems to sucessfully work around the Could not get port identifier, maybe insufficient permissions. issue.

Hey,
I’m having same problem in my OH3M2.
After few days serial modbus stoped working. An now it gives:

2020-11-20 10:42:50.991 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/1 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@180b55[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@89eacd[portName=/dev/ttyUSB0]
2020-11-20 10:42:50.992 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - re-connect reached max tries 1, throwing last error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@180b55[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@89eacd[portName=/dev/ttyUSB0]
2020-11-20 10:42:50.994 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@180b55[portName=/dev/ttyUSB0,port=<null>] for endpoint ModbusSerialSlaveEndpoint@89eacd[portName=/dev/ttyUSB0]: Could not get port identifier, maybe insufficient permissions. null
2020-11-20 10:42:50.996 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Could not connect to endpoint ModbusSerialSlaveEndpoint@89eacd[portName=/dev/ttyUSB0] -- aborting request ModbusReadRequestBlueprint@1d174b8[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=30,length=2,maxTries=3] [operation ID ba0b7154-5502-49f5-a389-c26859afd956]

Did someone managed to fix it?

As stated above, I compiled the serial library without locks and it works without problems since a week.

Here is the JAR with disabled locks: https://cloud.cc-h.de/index.php/s/u1fbjFhowhlFMjl

It replaces the JAR in this location:
/usr/share/openhab/runtime/system/com/neuronrobotics/nrjavaserial/5.2.1

1 Like

Thank You very much! It is working now.
Question: does people making new OH3 know about this so they would implement this in new versions?

@fwolter to my understanding this would be mean new openHAB 2.5 core release (Is nrjavaserial still maintained?) which is likely not going to happen anymore since 3.0 is hopefully soon out.

Looks like in 3.0 the situation is better?

Modbus binding itself cannot unfortunately control the nrjavaserial library provided by the OH runtime.

@Kamil_Matuszczak and I encountered the problem with OH3.M2, which uses a newer version of nrjavaserial. The question is if this a general problem with the newer nrjavaserial version. @ssalonen did you already try OH3 with modbus?

Did You write ticket in github OH3M2 distro?
Cause now we changed it manually, but after Update of OH3 to M3 we will need another time to change it manually…

No extensive tests, no. Tcp seemed to work fine

No changes between and 2.5 and 3.0, so any issues should be explainable by core issues and dependencies like nrjavaserial

I will file an issue on GitHub. Still interesting if this affects all OH3 users.

1 Like

OK so after one night I se another error.
I use two Modbus things.
One Serial and one TCP.

After few hours of normal work with changed nrjavaserial it stopped reading data from serial and tcp without any errors and log informations. after restarting modbus binding everything started normally.

Another thing I see that I cant change Time Between Transactions. Even if I give in file this to 6000 milisec, than after puting it on raspberry in UI I see still 60 milisec.

here is my thing file:

Bridge modbus:tcp:SolarEdgeConverter [ host=“192.168.31.47”, port=1502, id=1, timeBetweenTransactionsMilli=6000, timeBetweenReconnectMillis=0, connectMaxTries=3, reconnectAfterMillis=0, connectTimeoutMillis=5000 ] {
Bridge poller Registers [ start=69, length=50, refresh=5000, type=“holding” ] {
Thing data C_SunSpec_DID [ readStart=“69”, readValueType=“uint16” ] // 101 = single phase, 102 = split phase, 103 = three phase
Thing data C_SunSpec_Length [ readStart=“70”, readValueType=“uint16” ] // 50 = Length of model block
Thing data I_AC_Current [ readStart=“71”, readValueType=“uint16” ] // AC Total Current value
Thing data I_AC_CurrentA [ readStart=“72”, readValueType=“uint16” ] // AC Phase A Current value
//Thing data I_AC_CurrentB [ readStart=“73”, readValueType=“uint16” ] // AC Phase B Current value
//Thing data I_AC_CurrentC [ readStart=“74”, readValueType=“uint16” ] // AC Phase C Current value
Thing data I_AC_Current_SF [ readStart=“75”, readValueType=“int16” ] // AC Current scale factor
Thing data I_AC_VoltageAB [ readStart=“76”, readValueType=“uint16” ] // AC Voltage Phase AB value
//Thing data I_AC_VoltageBC [ readStart=“77”, readValueType=“uint16” ] // AC Voltage Phase BC value
//Thing data I_AC_VoltageCA [ readStart=“78”, readValueType=“uint16” ] // AC Voltage Phase CA value
//Thing data I_AC_VoltageAN [ readStart=“79”, readValueType=“uint16” ] // AC Voltage Phase A to N value
//Thing data I_AC_VoltageBN [ readStart=“80”, readValueType=“uint16” ] // AC Voltage Phase B to N value
//Thing data I_AC_VoltageCN [ readStart=“81”, readValueType=“uint16” ] // AC Voltage Phase C to N value
Thing data I_AC_Voltage_SF [ readStart=“82”, readValueType=“int16” ] // AC Voltage scale factor
Thing data I_AC_Power [ readStart=“83”, readValueType=“int16” ] // AC Power value
Thing data I_AC_Power_SF [ readStart=“84”, readValueType=“int16” ] // AC Power scale factor
Thing data I_AC_Frequency [ readStart=“85”, readValueType=“uint16” ] // AC Frequency value
Thing data I_AC_Frequency_SF [ readStart=“86”, readValueType=“int16” ] // Scale factor
Thing data I_AC_VA [ readStart=“87”, readValueType=“int16” ] // Apparent Power
Thing data I_AC_VA_SF [ readStart=“88”, readValueType=“int16” ] // Scale factor
Thing data I_AC_VAR [ readStart=“89”, readValueType=“int16” ] // Reactive Power
Thing data I_AC_VAR_SF [ readStart=“90”, readValueType=“int16” ] // Scale factor
Thing data I_AC_PF [ readStart=“91”, readValueType=“int16” ] // Power Factor
Thing data I_AC_PF_SF [ readStart=“92”, readValueType=“int16” ] // Scale factor
Thing data I_AC_Energy_WH [ readStart=“93”, readValueType=“uint32” ] // AC Lifetime Energy Production
Thing data I_AC_Energy_WH_SF [ readStart=“95”, readValueType=“uint16” ] // Scale factor
Thing data I_DC_Current [ readStart=“96”, readValueType=“uint16” ] // DC Current value
Thing data I_DC_Current_SF [ readStart=“97”, readValueType=“int16” ] // Scale factor
Thing data I_DC_Voltage [ readStart=“98”, readValueType=“uint16” ] // DC Voltage value
Thing data I_DC_Voltage_SF [ readStart=“99”, readValueType=“int16” ] // Scale factor
Thing data I_DC_Power [ readStart=“100”, readValueType=“int16” ] // DC Power value
Thing data I_DC_Power_SF [ readStart=“101”, readValueType=“int16” ] // Scale factor
Thing data I_Temp_Sink [ readStart=“103”, readValueType=“int16” ] // Heat sink temperature
Thing data I_Temp_SF [ readStart=“106”, readValueType=“int16” ] // Scale factor
Thing data I_Status [ readStart=“107”, readValueType=“uint16”] // Operating state
Thing data I_Status_Vendor [ readStart=“108”, readValueType=“uint16”] // Vendor-defined operating state and error codes
}
}

And what I see in UI:

Hello,
My modbus rtu connection also dropped after a few hours but the strange thing was that only the coils no longer reacted, the discrete inputs continued to work.

I had the problem from 2.5.7, now I am on openhab3 m2 I have searched for a long time and could not find a solution, no errors were displayed, not even with trace logging.After a restart, everything always worked right back. I reinstalled everything again and then I first just installed the modbus binding and then everything just kept working the problem started after installing the chromecast binding?

For now I will try to write rule that will restart binding if reading will not change for amount of time.
But this it not a right way to do it.

Do you have typo here?

1 Like

OH3M2?

M2 should include at least https://github.com/openhab/openhab-addons/pull/8461

Can you please troubleshoot the issue with steps described in Modbus stops without any errors

Yes it is OH3M2.
Will try to check logs

Ok so yesterday I installed latest OH3 Snapshot.

And after few hours of working it stopped reading modbus data.
Then I restarted modbus binding but only TCP reading got back serial didnt work.

I got this errors:

2020-11-22 23:55:25.321 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - connect try 1/1 error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@1f110f1[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@f853cd[portName=/dev/ttyUSB0]
2020-11-22 23:55:25.323 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - re-connect reached max tries 1, throwing last error: Could not get port identifier, maybe insufficient permissions. null. Connection SerialConnection@1f110f1[portName=/dev/ttyUSB0,port=<null>]. Endpoint ModbusSerialSlaveEndpoint@f853cd[portName=/dev/ttyUSB0]
2020-11-22 23:55:25.324 [ERROR] [ing.ModbusSlaveConnectionFactoryImpl] - Error connecting connection SerialConnection@1f110f1[portName=/dev/ttyUSB0,port=<null>] for endpoint ModbusSerialSlaveEndpoint@f853cd[portName=/dev/ttyUSB0]: Could not get port identifier, maybe insufficient permissions. null
2020-11-22 23:55:25.325 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Could not connect to endpoint ModbusSerialSlaveEndpoint@f853cd[portName=/dev/ttyUSB0] -- aborting request ModbusReadRequestBlueprint@110611[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=70,length=2,maxTries=3] [operation ID f51593c1-9f13-4b58-8bb2-c3f132baf1db]

I will try once again to replace nrjavaserial and check what will change.
Are there any github issue opened with this?

So here are files for troubleshoot.

OpenHAB 3.0.0-SNAPSHOT (#2024)

thread-locks.txt (153.3 KB) threads.txt (134.8 KB)

threads-locks.txt indicate that it seems to be busy reading serial data. There should be timeout to prevent any “hanging”. In fact, it seems with threads.txt the situation is already different, all the pollers are idling, perhaps waiting for the next poll round.

What was the situation when you took these thread stack traces? The diagnostics are only useful to capture when the system seems to be stuck.

In addition, I appreciate if you can follow the troubleshooting advice given in the post.

Do you have full logs to send me please?
how does the last success item update? Does it stop updating?
how does the last error item update? Does it stop updating?

(thread-locks.txt)

"OH-modbusManagerPollerThreadPool-5" Id=217 in RUNNABLE
    at gnu.io.RXTXPort.readByte(Native Method)
    at gnu.io.RXTXPort$SerialInputStream.read(RXTXPort.java:1344)
      - locked gnu.io.RXTXPort$SerialInputStream@1f4b2e9
    at net.wimpi.modbus.io.ModbusRTUTransport.readResponse(ModbusRTUTransport.java:125)
      - locked net.wimpi.modbus.io.BytesInputStream@1229b4b
    at net.wimpi.modbus.io.ModbusSerialTransaction.execute(ModbusSerialTransaction.java:195)
      - locked net.wimpi.modbus.io.ModbusRTUTransport@a25324
    at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$0(ModbusManagerImpl.java:208)
    at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation$$Lambda$1053/0x976e4828.run(Unknown Source)