Smartmeter Binding throws "unable to open port" after a while

Possibly related

1 Like

first thing, I changed the refresh rate again to the default 30 sec. It was on 5sec to get faster updates. This seems to reduce the errors reported.
I just scanned through my log file and this is the overview of errors reported there (after an OH restart yesterday):
2020-03-10 17:58:19.194 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: Termination sequence is wrong. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-10 17:58:51.773 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-10 19:56:10.454 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: Termination sequence is wrong. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-10 19:56:42.974 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-10 21:33:21.613 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: Termination sequence is wrong. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-10 21:33:54.174 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 00:38:54.029 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: Termination sequence is wrong. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 00:39:26.537 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 03:16:01.347 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: Termination sequence is wrong. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 03:16:33.852 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 03:31:34.906 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 05:11:19.548 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: Termination sequence is wrong. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 05:11:52.098 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 08:57:10.595 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 09:29:14.078 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: Termination sequence is wrong. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816
2020-03-11 09:29:46.644 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds…; smartmeter:meter:44427816

Every few hours there is an error. Most of the time it complains about the termination sequence and the subsequent read fails with wrong crc.

The system is stable for now, perhaps it got better with the increased refresh rate…

Regards,
Thomas

Looks like your hardware setup is not in a good shape. These CRC errors are supposed to be very rare!

I haven’t checked, but it is not unlikely that the handling of connection errors has changed in the new code and is causing some new issues with your specific setup.

Having said that, the fact that some hardware device or setup worked for (quite) a while is in no way proof that it is still in good shape. Anything can break any moment. :sunglasses: And it might just have been that somehow the cable has accidentally been touched lately…

… or some new unrelated device has introduced interference. I would imagine a meter signal cable is running amongst power feed cables.

To add to what @noppes123 says, the Modbus issue I pointed at involved a serial error that ought to be recoverable causing a port hangup instead. Something in the shared system serial module.
The hangup is likely a new issue … the underlying recoverable errors could have been there forever, usually recovered.

1 Like

Good point. I do not think USB cable is shielded.

Thanks for your analysis!

I will now look into my hardware setup in detail and try to get rid of these errors.

Regards,
Thomas

2 Likes

I come across the very same effect, with 2 of those sensors connected to Raspi via USB, both running into the same crc error resonably often, every few minutes. It usually recovers in next query, but stresses system and OH with broken connection and re-establishment. With OH 2.3 connection was stable, issue appears since 2.4. So might lead to the reported issue around nrjavaserial?

Hi,
I use smartmeter with Rasp-Installation OH2.5 and this works fine for several month.
Now I installed Ubuntu-VM in QNAP-453d with my OH2.5 installation and the smartmeter-Bindung throws the same Error as above.
I tried also a new, fresh Installation on VM with same effect.
The Binding works five minutes, then stops with the “wrong crc” message.
But the ttyUSB0 ist active on maschine.
After OH restart, works five minutes, then stops…
Any ideas?

Dear community,

seems like I‘m running into the same issue. I have been using Volkszaehler for monitoring my power meter for 1.5 years without issues, now I want to move everything to openHAB to avoid a hybrid solution running both.

My power meter is an EasyMeter Q3M and I use the common USB infrared sensor/reader from Weidmann. Cable I’m using is the original USB cable from Weidmann which seems to be just a standard cable without any special shielding etc. – I ordered a new (better?) USB cable and ferrit rings to see if the CRC issues are caused by the main power cable which runs parallel to the USB cable. I will let you know about the outcome. Hardware wise this is my last straw.

This is my thing:

smartmeter:meter:BinderPower     [port="/dev/strom", mode="SML", baudrate=9600, refresh=10] {}

My CRC error sequence from the logs/events, everything is handled within a few seconds. Warning, error, opening, running - every few minutes the same story.

==> /var/log/openhab2/openhab.log <==
2021-01-08 10:18:34.381 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: wrong crc. Closing connection and trying again in 2 seconds...; smartmeter:meter:BinderPower
java.io.IOException: wrong crc
	at org.openmuc.jsml.transport.MessageExtractor.handleEnd(MessageExtractor.java:112) ~[bundleFile:?]
	at org.openmuc.jsml.transport.MessageExtractor.waitForStopSequence(MessageExtractor.java:88) ~[bundleFile:?]
	at org.openmuc.jsml.transport.MessageExtractor.getSmlMessage(MessageExtractor.java:42) ~[bundleFile:?]
	at org.openmuc.jsml.transport.Transport.getSMLFile(Transport.java:101) ~[bundleFile:?]
	at org.openhab.binding.smartmeter.internal.sml.SmlSerialConnector.readNext(SmlSerialConnector.java:95) ~[bundleFile:?]
	at org.openhab.binding.smartmeter.internal.sml.SmlSerialConnector.readNext(SmlSerialConnector.java:1) ~[bundleFile:?]
	at org.openhab.binding.smartmeter.connectors.ConnectorBase.emitValues(ConnectorBase.java:152) ~[bundleFile:?]
	at org.openhab.binding.smartmeter.connectors.ConnectorBase.lambda$2(ConnectorBase.java:123) ~[bundleFile:?]
	at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual(FlowableCreate.java:71) [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.FlowableFlatMap$MergeSubscriber.onNext(FlowableFlatMap.java:163) [bundleFile:?]
	at io.reactivex.internal.operators.flowable.FlowableTimer$TimerSubscriber.run(FlowableTimer.java:76) [bundleFile:?]
	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:38) [bundleFile:?]
	at io.reactivex.internal.schedulers.ScheduledDirectTask.call(ScheduledDirectTask.java:26) [bundleFile:?]
	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:834) [?:?]
==> /var/log/openhab2/events.log <==
2021-01-08 10:18:34.489 [hingStatusInfoChangedEvent] - 'smartmeter:meter:BinderPower' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): wrong crc
==> /var/log/openhab2/openhab.log <==
2021-01-08 10:18:36.490 [INFO ] [ding.smartmeter.internal.MeterDevice] - Opening connection to smartmeter:meter:BinderPower
==> /var/log/openhab2/events.log <==
2021-01-08 10:18:46.591 [hingStatusInfoChangedEvent] - 'smartmeter:meter:BinderPower' changed from OFFLINE (COMMUNICATION_ERROR): wrong crc to ONLINE

Maybe this input might help in this regard.

Dear colleagues,

I received my new (better?) USB cable yesterday as well as a package of different sizes of ferrite rings/cores. Before I had up to two CRC issues per minute in openHAB, now it’s fine. I cannot say if the issue already existed with Volkszaehler, maybe there is no logging for CRC issues implemented. At least I didn’t notice.

After I attached the new cable with two ferrite rings/cores on each end of the cable my logs regarding the CRC issues went crazy. After I restarted openHAB (not the Raspberry Pi itself) the issue almost seems to be solved. I encountered two CRC issues yesterday and so far zero for today.

I cannot determine if a simple restart of openHAB solved it or if the invest of ~20€ for the cable and ferrite cores/rings are the fix.

It would be nice if someone else might be willing to purchase similar items and give some feedback.

I purchased the following items on Amazon (let me know if links like these are not allowed here, but maybe it helps for some users):

Thanks and best regards,
Markus

1 Like

Hi, is your problem still solved?

I have the same problem running OH3.1.0 M2 on an Odroid C4.

I randomly receive the “Wrong CRC” messages and at some point, the «smart meter» thing can not connect to the serial port anymore and the communication stays offline. From that point no more data can be read from the meter and I have to restart openhab.

I also changed the USB-Cable (from 5m to 2m) but still the same error.

Looking into the logs gives output like this. Anyone got an idea?

~$ dmesg --human|tail

[ +0,000769] cp210x ttyUSB0: failed set request 0x7 status: -32

[ +0,017139] cp210x ttyUSB0: failed set request 0x7 status: -32

[ +0,003254] cp210x ttyUSB0: failed set request 0x7 status: -32

[ +2,007947] cp210x ttyUSB0: failed set request 0x7 status: -32

[ +0,004078] cp210x ttyUSB0: failed set request 0x7 status: -32

[Mär 9 17:30] cp210x ttyUSB0: failed set request 0x7 status: -32

[ +0,001602] cp210x ttyUSB0: failed set request 0x7 status: -32

[ +0,098042] cp210x ttyUSB0: failed set request 0x7 status: -32

[ +2,017156] cp210x ttyUSB0: failed set request 0x7 status: -32

[ +0,005807] cp210x ttyUSB0: failed set request 0x7 status: -32
~$ dmesg | grep USB

[27416.939672] cp210x ttyUSB0: failed set request 0x7 status: -32

[27418.956828] cp210x ttyUSB0: failed set request 0x7 status: -32

[27418.962635] cp210x ttyUSB0: failed set request 0x7 status: -32

Infromation about USB-device:

~$ lsusb
Bus 002 Device 002: ID 2109:0817 VIA Labs, Inc. USB3.0 Hub
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 004: ID 0403:6001 Future Technology Devices International, Ltd FT232 Serial (UART) IC
Bus 001 Device 003: ID 10c4:ea60 Silicon Labs CP210x UART Bridge
Bus 001 Device 002: ID 2109:2817 VIA Labs, Inc. USB2.0 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
1 Like

Actually I have two brand new USB cable around here for quite a while. Since its not easy to exchange the old ones, I didn’t do it yet.
For the time being I have built a workaround script that just restarts my OH (or even the raspi itself) if there are some errors :-):

#!/bin/bash

# ANY_OFFLINE calculation:
# 1. We check every openhab thing
# curl http://localhost:8080/rest/things
# 2. Pipe it to jq
# jq
# 3. Build an Array of OFFLINE things
# 3.1. Array
# [...]
# 3.2. Check every element of thing array array to be OFFLINE
# .[] | select(.statusInfo.status=="OFFLINE")
# 3.3. Extract the UID
# | .UID
# 3.4. Filter only smartmeter things
# | startswith("smartmeter") | select(. == true)
# 4. From the resulting array of booleans check of any is true (means there exists an OFFLINE element from smartmeter)
# [...] | any
# Result is true / false
echo "Running check for offline things..."

ANY_OFFLINE=$(/usr/bin/curl --silent http://localhost:8080/rest/things | /usr/bin/jq --raw-output '[.[] | select(.statusInfo.status=="OFFLINE") | .UID | startswith("smartmeter") | select(. == true)] | any')

if [ "$ANY_OFFLINE" == "false" ]; then
  echo "$(date): Online" >> /tmp/offline_log.txt
  rm -f /tmp/smartmeter_offline
  exit 0
fi

if [ -f /tmp/smartmeter_offline ]; then
  rm -f /tmp/smartmeter_offline
  echo "$(date): Offline" >> /tmp/offline_log.txt
  FAILED_MODEM_LINES=$(cat /var/log/syslog | grep "failed to get modem status" | wc -l)
  INPUT_OVERRUN_LINES=$(cat /var/log/syslog | grep ttyUSB | grep "input overrun" | wc -l)
  if (($FAILED_MODEM_LINES > 10)) || (($INPUT_OVERRUN_LINES > 10)); then 
      echo "Rebooting now!" >> /tmp/offline_log.txt
      /sbin/reboot --reboot 
  else
      echo "Restarting OH now!" >> /tmp/offline_log.txt
    systemctl restart openhab2.service
  fi
else
  echo "$(date): Offline" >> /tmp/offline_log.txt
  touch /tmp/smartmeter_offline
fi

Since this OH instance is only for my smart meters and other less important sensors, I can live with some restarts once a while.
My plan is to re-do most of this and exchange the cables once I switch to OH3 and then a Raspi4 with a docker based installation.

Regards,
Thomas

Thank you. That is quite a hard workaround, but at the moment I don´t see any alternative… :frowning:
Are you using OH2?

As seen in other bindings, there does appear to be some problem in the common underlying serial library, which appears to manifest as serial port locking out during what should be a “routine” error recovery sequence.
Tagging the github issue as this may be what you are seeing too,

Any news on that topic?

I think there is a success in implementing a workaround on the modbus binding which avoids the lock of the serial port. See here:

I don’t know if the same workaround is working with the smart meter binding and if it will be implemented.
But I am also very interested in a solution here.

I still have the same problem here.
Running OH3.1.0 M5 now.
I am not sure when the fix in the nrjavaserial serial libary will be ready…?
What I am wondering: I am also runnging the ComfoAir Binding. The communication to the ventilation-system is also done over a serial connection. This connection is running absolutly stable and reliable since months. I am not a programmer, but I think the “buggy” serial libary is not used here.

@boehan Sorry for pointing you directly. Maybe you can tell how the serial connection is done with the ComfoAir binding? Is there a way to use the same way to communicate with the Smartmeter binding?

@Tuny my knowledge about serial communication is rather limited thus I have not much to add here. Having a quick look at the code of the smartmeter binding it just uses the available core libraries for the serial connector, just as the comfoair binding does.
From a rough read over this thread I’d assume that your connection to the smartmeter is just more unstable than that to the comfoair, e.g. due to interference, bad/longer cable, etc., which then causes the connection to get blocked.
However, I just saw, that the related bug in the error handling of nrjavaserial is fixed upstream and should find its way in OH soon (see Serial ports getting blocked after some re-connecting · Issue #1842 · openhab/openhab-core · GitHub)

2 Likes

OK, that makes sense. The connection to the smart meter is done over an optical probe. So there might be more reading errors and delays.
Thank you very much for your investigation.

Hi there!
I just stumbled into the same error; First I was very positively surprised how easy it was to get the optocoupler delivering useful values from my feed-in-counter.
But the next morning the state was the one discussed above. Rarely I do get that thing " go green" - no matter what I try. And now I stumbled into this thread…
The only useful I can tribute here is that in my case it doesn’t seem to be connected to the same issue disturbing Modbus-communication. My openhab system communicates with 3 different solar and battery inverters without any problems at all since a long time…
Did anybody get further in this case?
Best regards,
Ansgar