No serial connection with Smartmeter Binding after update to OH3

Digitalvitamin · April 25, 2022, 8:00pm

Hi,
after using openHAB 2.5 on a Synology for a while I needed to update now.

I’m now running openHAB 3.2.0. In preparation I had to do the switch from Oracle Java 8 to Azul Java 11. In order to connect to a Weidmann Smart Meter reader I was happily using the Smartmeter binding with OH 2.5 and the following things configuration:

smartmeter:meter:powermeter [port="/dev/ttyUSB0", refresh=10]

With 2.5 everything worked fine. After the switch I constantly (and instantly) get “No provider for port /dev/ttyUSB0 found” and the Smartmeter-Thing never comes online.

Searching the forum I came across several similar posts:

Also I checked the docs for the Serial Port Configuration.

Before writing this I checked and tried the following:

cat /dev/ttyUSB0 produces binary output on the console
User openhab has access rights to the device:

$ ls -al /dev/ttyUSB0 
crwxrwxr-x 1 openhab users 188, 0 Apr 25 06:44 /dev/ttyUSB0

To be sure I also added the openhab user to the group dialout
I’ve also added EXTRA_JAVA_OPTS: -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0
Upgraded nrjavaserial to 5.2.1.OH1
Restarted several times in between the steps.
Played around with different refresh times (5, 10, 30)
Removed the textual configuration and added it via UI

From the log (DEBUG):

2022-04-25 17:14:12.053 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Opening connection to smartmeter:meter:powermeter
2022-04-25 17:14:12.056 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Failed to read: No provider for port /dev/ttyUSB0 found. Closing connection and trying again in 2 seconds...; smartmeter:meter:powermeter
java.lang.IllegalStateException: No provider for port /dev/ttyUSB0 found
        at org.openhab.binding.smartmeter.internal.sml.SmlSerialConnector.openConnection(SmlSerialConnector.java:137) ~[bundleFile:?]
        at org.openhab.binding.smartmeter.internal.MeterDevice.lambda$1(MeterDevice.java:168) ~[bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableDoOnLifecycle$SubscriptionLambdaSubscriber.onSubscribe(FlowableDoOnLifecycle.java:63) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableTimeoutTimed.subscribeActual(FlowableTimeoutTimed.java:47) [bundleFile:?]
        at io.reactivex.Flowable.subscribe(Flowable.java:14479) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableDoOnLifecycle.subscribeActual(FlowableDoOnLifecycle.java:38) [bundleFile:?]
        at io.reactivex.Flowable.subscribe(Flowable.java:14479) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableDoOnEach.subscribeActual(FlowableDoOnEach.java:50) [bundleFile:?]
        at io.reactivex.Flowable.subscribe(Flowable.java:14479) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableDoOnLifecycle.subscribeActual(FlowableDoOnLifecycle.java:38) [bundleFile:?]
        at io.reactivex.Flowable.subscribe(Flowable.java:14479) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableDoOnEach.subscribeActual(FlowableDoOnEach.java:50) [bundleFile:?]
        at io.reactivex.Flowable.subscribe(Flowable.java:14479) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowablePublish.connect(FlowablePublish.java:130) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableRefCount.subscribeActual(FlowableRefCount.java:91) [bundleFile:?]
        at io.reactivex.Flowable.subscribe(Flowable.java:14479) [bundleFile:?]
        at io.reactivex.Flowable.subscribe(Flowable.java:14426) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableRepeatWhen$WhenReceiver.onNext(FlowableRepeatWhen.java:100) [bundleFile:?]
        at io.reactivex.subscribers.SerializedSubscriber.onNext(SerializedSubscriber.java:100) [bundleFile:?]
        at io.reactivex.internal.operators.flowable.FlowableDelay$DelaySubscriber$OnNext.run(FlowableDelay.java:114) [bundleFile:?]
        at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker$BooleanRunnable.run(ExecutorScheduler.java:260) [bundleFile:?]
        at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker.run(ExecutorScheduler.java:225) [bundleFile:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:829) [?:?]

This seems to happen because the SmlSerialConnector can’t get an id for the portName (/dev/ttyUSB0):

github.com

openhab/openhab-addons/blob/main/bundles/org.openhab.binding.smartmeter/src/main/java/org/openhab/binding/smartmeter/internal/sml/SmlSerialConnector.java#L107

      
        
                if (smlFiles.isEmpty()) {
                    throw new IOException(getPortName() + " : There is no SML file in buffer. Try to increase Refresh rate.");
                }
                logger.debug("{} : Read {} SML files from Buffer", this.getPortName(), smlFiles.size());
                return smlFiles.pop();
            }
            
            
@Override
            public void openConnection() throws IOException {
                closeConnection();
                SerialPortIdentifier id = serialManagerSupplier.get().getIdentifier(getPortName());
                if (id != null) {
                    try {
                        serialPort = id.open("meterreaderbinding", 0);
                    } catch (PortInUseException e) {
                        throw new IOException(MessageFormat
                                .format("Error at SerialConnector.openConnection: unable to open port {0}.", getPortName()), e);
                    }
                    SerialParameter serialParameter = SerialParameter._8N1;
                    int baudrateToUse = this.baudrate == Baudrate.AUTO.getBaudrate() ? Baudrate._9600.getBaudrate()
                            : this.baudrate;

But why?

I don’t know what else I could try.

Has anyone any idea what else to test or to do?
Could it somehow be related to the Azul Java (OpenJDK Runtime Environment Zulu11.54+25-CA (build 11.0.14.1+1-LTS))?

splatch · April 25, 2022, 8:27pm

The default openHAB serial provider have a whitelist of permitted serial ports to touch. You need to update setenv and append again the port name: Serial Port Configuration | openHAB

Digitalvitamin · April 25, 2022, 8:35pm

You mean something like this in openHAB/runtime/bin/setenv?

export EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0 ${EXTRA_JAVA_OPTS}"

That’s what I already tried in step 4. above.

splatch · April 25, 2022, 8:53pm

I missed apparently steps you made and went directly to solution, system config seems fine. If you have troubles with accessing serial port there there are very few things left beside blaming of system. The serial port API in openHAB didn’t change much, native part of serial port library did evolve a bit, but its rather further stabilization than revolution.

You can try alternate serial port provider (one you linked is what I wrote a while ago), be aware that it can’t run in parallel with default one and serial port identifiers will change from /dev/ttyUSB0 to ttyUSB0. But before you go that path its important to confirm that openhab user can read port. Normally when you enter NAS you do that using some kind of admin user which has more privileges than software running on it. Can you check if sudo -u openhab cat /dev/ttyUSB0 or similar produces any output?

Digitalvitamin · April 26, 2022, 6:10pm

Thanks for trying to help me…
sudo -u openhab cat /dev/ttyUSB0 produces binary output

I also unplugged the device, plugged it in again and reassigned rights and user - still the same issue even after restarting openHAB.

Any other idea or is it time for the alternate provider?

In another forum I’ve read to also do this:

chown -R root.users /var/lock
chmod 775 /var/lock

Digitalvitamin · April 26, 2022, 7:10pm

Indeed this did the trick :

To be complete I did the same for /var/run/lock
I can see now that the following file is created in /var/run/lock:
-rw-r--r-- 1 openhab users 11 Apr 26 21:00 LCK..ttyUSB0
This worked instantly - even without restart.

I don’t think this was necessary for OH 2.5, though… so something to note down.
Perhaps the provide could dump an error message when the directory is not writable?

wborn · April 26, 2022, 8:02pm

Looks like you’ve ran into openhab-core#2474. It’s only an issue on certain OS-es. For instance on Debian/Ubuntu any process can write to /var/lock.

wborn · April 26, 2022, 8:40pm

I’ve created a PR to add some docs for this: