SML Reader - how to integrate

msteigenberger · December 29, 2018, 6:02pm

@wolkenjaeger: your meter supports no standard protocol it seems. The binding only supports SML and IEC62051-21 currently.

wolkenjaeger · January 7, 2019, 10:47pm

Thanks for the answer. I am very confused, because the manual of the meter clearly states it is compatible with mode “C” …
Would you mind adding debugging information on the binding to include the “sent” and “recieved” messages?

msteigenberger · January 20, 2019, 3:26pm

Sorry for late answer, did not recognize your post.
You’re absolutely right, it supports 62056-21, my research was wrong.
Can you please give me a log with protocol set to iec62056-21 (your last log was with SML}.

Joerg_Schreiner · February 7, 2019, 4:24pm

Hi,
i also have an issue with the inability to show negative values for 16.7.
I identified following waring in my openhab.log:

2019-02-07 16:10:20.790 [WARN ] [martmeter.internal.SmartMeterHandler] - Failed to apply negation for channel: smartmeter:meter:4e4b73f6:1-0_16-7-0
_java.lang.NumberFormatException: For input string: “281.8”

I haven’t defined any negation in the channel.
before I moved to 2,5M1, I had 2.3 successfully running with negative values

wolkenjaeger · February 10, 2019, 4:57pm

Hi again,
I finally had some time to dive into this. It looks like it does not get the connection to the USB-Serial. However:

I am (pretty) sure, I had all the permission set on Debian/Java - is this fact visible in the log or would it say something like “no permission to connect to USB” or similar?
I am also sure it works, because I can use a test script from volkszähler.

Logfile attached from openhab2:
openhab_short.txt (5.2 KB)

msteigenberger · February 21, 2019, 6:40pm

@Joerg_Schreiner: From the warning you get, it seems you’ve configured a negate property in your channel configuration. To verify it, can you please set the log level to DEBUG or TRACE and attach a complete log here?

msteigenberger · February 21, 2019, 6:58pm

@wolkenjaeger:

would it say something like “no permission to connect to USB” or similar

Yes, it would tell you that the port can not be opened. Actually it found the port and established a connection to it. There was just no data sent for 30 seconds.

Would you mind adding debugging information on the binding to include the “sent” and “recieved” messages

Unfortunately this is not under the binding’s control. It is done via the j62056 library which writes the debug information (send and read bytes) to the console (not the log file). I’m not sure whether openhab is by default configured to forward it to the log. Otherwise you need to redirect the output manually to a file.

From the log you’ve sent, I cannot get which configuration you actually have set now. Can you tell me:

Protocol (IEC62056/SML)
mode (A/B/C, D)
refresh

wolkenjaeger · February 21, 2019, 8:42pm

Thanks for helping. I try to get a grip on the stdout of openhab then. Don’t know how to do yet, but I guess there is a solution around. In the meantime here is my config:

greenoid · March 3, 2019, 6:56pm

The help message on the protocol to use is absolutly misleading.
Through try and error I found out that the protocol name is “ABC”!
Not “A,B,C” oder just “C” or “A/B/C” oder “Mode A,B,C” !
The other valid modes are “SML” and “D”.

msteigenberger · March 5, 2019, 7:51am

The Protocol modes are either A OR B OR C OR D.
For modes A, B or C they are negotiated with the meter -> Therefore there is no need for the user to distinguish between them. Mode D is pure push mode where negotiation is not possible.

greenoid · March 16, 2019, 9:40am

In MeterFactoryFactory.java you have:
switch (protocolMode) {
case D:
case ABC:
return new Iec62056_21MeterReader(serialPortManagerSupplier, deviceId, serialPort, initMessage,
baudrate, baudrateChangeDelay, protocolMode);
case SML:
return SmlMeterReader.createInstance(serialPortManagerSupplier, deviceId, serialPort, initMessage,
baudrate, baudrateChangeDelay);
default:
return null;

    ProtocolMode protocolMode = ProtocolMode.valueOf(mode.toUpperCase());
    switch (protocolMode) {
        case D:
        case ABC:
            return new Iec62056_21MeterReader(serialPortManagerSupplier, deviceId, serialPort, initMessage,
                    baudrate, baudrateChangeDelay, protocolMode);
        case SML:
            return SmlMeterReader.createInstance(serialPortManagerSupplier, deviceId, serialPort, initMessage,
                    baudrate, baudrateChangeDelay);
        default:
            return null;

In ProtocolMode.java you have:
public enum ProtocolMode {

ABC("A,B,C"),
D("D"),
SML("SML");

Now my test:

package de.greenoid;

import de.greenoid.ProtocolMode;

public class EnumTest {

public static void main(String[] args) {
	String mode;
	mode = "ABC";
	
	ProtocolMode pmode = ProtocolMode.valueOf(mode);
	
	System.out.println(pmode.toString()); // prints "ABC"
	
	mode = "A";
	
	pmode = ProtocolMode.valueOf(mode);
	
	System.out.println(pmode.toString());  // gives NullPointerException
}

}

So valueOf(“A”) does not find the enum “ABC”.

Thanks for your binding!

Frerk

greenoid · March 16, 2019, 10:26am

Problem: Only first reading succcessful, no more readings afterwards

I have a Landis+Gyr E350 Smartmeter which reports OBIS Codes with the Volkszaehler IR USB reader attached.

I configured it as Mode “ABC”, see posting above.

After each restart the first reading reads all OBIS codes, but the binding does not recognize it as successful, runs into the timeout of 30 seconds, retries every 2 seconds but never succeeds.

Here is the log after restart of OpenHAB 2.4:

2019-03-16 10:51:39.229 [INFO ] [ding.smartmeter.internal.MeterDevice] - Read out following values: Device: smartmeter:meter:fcd54a9a
Obis: 1.8.3 MeterValue [obis=1.8.3, value=000000.000, unit=kWh]
Obis: 2.8.0 MeterValue [obis=2.8.0, value=000000.000, unit=kWh]
Obis: 1.8.4 MeterValue [obis=1.8.4, value=000000.000, unit=kWh]
Obis: C.5.0 MeterValue [obis=C.5.0, value=0401, unit=null]
Obis: C.7.0 MeterValue [obis=C.7.0, value=0002, unit=null]
Obis: C.1.1 MeterValue [obis=C.1.1, value=        , unit=null]
Obis: 0.2.0 MeterValue [obis=0.2.0, value=M27, unit=null]
Obis: C.1.0 MeterValue [obis=C.1.0, value=16261281, unit=null]
Obis: 15.8.0 MeterValue [obis=15.8.0, value=007920.853, unit=kWh]
Obis: 31.7 MeterValue [obis=31.7, value=00.461, unit=A]
Obis: 0.0 MeterValue [obis=0.0, value=16261281        , unit=null]
Obis: 1.8.0 MeterValue [obis=1.8.0, value=007920.853, unit=kWh]
Obis: 1.8.1 MeterValue [obis=1.8.1, value=007920.853, unit=kWh]
Obis: 1.8.2 MeterValue [obis=1.8.2, value=000000.000, unit=kWh]
Obis: 16.7 MeterValue [obis=16.7, value=000.34, unit=kW]
Obis: 71.7 MeterValue [obis=71.7, value=00.759, unit=A]
Obis: 72.7 MeterValue [obis=72.7, value=230, unit=V]
Obis: 51.7 MeterValue [obis=51.7, value=00.489, unit=A]
Obis: 52.7 MeterValue [obis=52.7, value=228, unit=V]
Obis: F.F MeterValue [obis=F.F, value=00, unit=null]
Obis: 32.7 MeterValue [obis=32.7, value=227, unit=V]

2019-03-16 11:06:05.844 [WARN ] [.iec62056.Iec62056_21SerialConnector] - 1. reading attempt failed: null. Retrying /dev/ttyUSB0...
2019-03-16 11:06:05.852 [WARN ] [.iec62056.Iec62056_21SerialConnector] - Delaying retry by PT20S
2019-03-16 11:06:09.320 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: The source did not signal an event for 30 seconds and has been terminated.. Closing connection and trying again in 2 seconds...; smartmeter:meter:fcd54a9a
java.util.concurrent.TimeoutException: The source did not signal an event for 30 seconds and has been terminated.
        at io.reactivex.internal.operators.flowable.FlowableTimeoutTimed$TimeoutSubscriber.onTimeout(FlowableTimeoutTimed.java:139) [206:org.openhab.binding.smartmeter:2.4.0]
        at io.reactivex.internal.operators.flowable.FlowableTimeoutTimed$TimeoutTask.run(FlowableTimeoutTimed.java:170) [206:org.openhab.binding.smartmeter:2.4.0]
        at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker$BooleanRunnable.run(ExecutorScheduler.java:260) [206:org.openhab.binding.smartmeter:2.4.0]
        at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker.run(ExecutorScheduler.java:225) [206:org.openhab.binding.smartmeter:2.4.0]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]

In python I succeeded even in switching the speed of the serial transmission to 4800 or 9600, but it is not necessary if the OBIS codes can be received in 300 baud.

What should I try?

TIA,

Frerk

msteigenberger · March 16, 2019, 10:40am

Got your concern with misleading documentation on A,B,C modes. You’re right!

Regarding your problem: Can you please set to trace logging (log:set trace org.openhab.binding.smartmeter) and append a openhab.log file here?

greenoid · March 16, 2019, 11:26am

This is a Heisenbug!
I started the trace level, stop the bundle smartmeter, started the bundle smartmeter and sensor values were read without error.
BUT
as soon as I tried to read it via Paper UI the same error occured.
The Thing was displayed as being offline.
BUT
after some time (~2min) it changed to being online.
So I classify the status as unreliable/flacky at the moment.

2019-03-16 12:19:18.050 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=0.2.0, value=M27, unit=null]
2019-03-16 12:19:44.622 [WARN ] [.iec62056.Iec62056_21SerialConnector] - 1. reading attempt failed: null. Retrying /dev/ttyUSB0…
2019-03-16 12:19:44.627 [WARN ] [.iec62056.Iec62056_21SerialConnector] - Delaying retry by PT20S
2019-03-16 12:19:48.058 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: The source did not signal an event for 30 seconds and has been terminated… Closing connection and trying again in 2 seconds…; smartmeter:meter:fcd54a9a
java.util.concurrent.TimeoutException: The source did not signal an event for 30 seconds and has been terminated.
at io.reactivex.internal.operators.flowable.FlowableTimeoutTimed$TimeoutSubscriber.onTimeout(FlowableTimeoutTimed.java:139) [206:org.openhab.binding.smartmeter:2.4.0]
at io.reactivex.internal.operators.flowable.FlowableTimeoutTimed$TimeoutTask.run(FlowableTimeoutTimed.java:170) [206:org.openhab.binding.smartmeter:2.4.0]
at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker$BooleanRunnable.run(ExecutorScheduler.java:260) [206:org.openhab.binding.smartmeter:2.4.0]
at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker.run(ExecutorScheduler.java:225) [206:org.openhab.binding.smartmeter:2.4.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
2019-03-16 12:19:50.164 [INFO ] [ding.smartmeter.internal.MeterDevice] - Opening connection to smartmeter:meter:fcd54a9a
2019-03-16 12:20:13.425 [DEBUG] [.iec62056.Iec62056_21SerialConnector] - Datamessage read: {
“data message”: {
“manufacturer ID”: “LGZ”,
“meter ID”: “ZMF100AC.M27”,
“enhanced ID/capability”: “”,
“data block”: {
“data set”: {“address”: “F.F”, “value”: “00”, “unit”: “”},
“data set”: {“address”: “C.1.0”, “value”: “16261281”, “unit”: “”},
“data set”: {“address”: “0.0”, “value”: "16261281 ", “unit”: “”},
“data set”: {“address”: “C.1.1”, “value”: " ", “unit”: “”},
“data set”: {“address”: “1.8.1”, “value”: “007921.472”, “unit”: “kWh”},
“data set”: {“address”: “1.8.2”, “value”: “000000.000”, “unit”: “kWh”},
“data set”: {“address”: “1.8.3”, “value”: “000000.000”, “unit”: “kWh”},
“data set”: {“address”: “1.8.4”, “value”: “000000.000”, “unit”: “kWh”},
“data set”: {“address”: “1.8.0”, “value”: “007921.472”, “unit”: “kWh”},
“data set”: {“address”: “2.8.0”, “value”: “000000.000”, “unit”: “kWh”},
“data set”: {“address”: “15.8.0”, “value”: “007921.472”, “unit”: “kWh”},
“data set”: {“address”: “32.7”, “value”: “229”, “unit”: “V”},
“data set”: {“address”: “52.7”, “value”: “227”, “unit”: “V”},
“data set”: {“address”: “72.7”, “value”: “230”, “unit”: “V”},
“data set”: {“address”: “31.7”, “value”: “00.462”, “unit”: “A”},
“data set”: {“address”: “51.7”, “value”: “00.444”, “unit”: “A”},
“data set”: {“address”: “71.7”, “value”: “01.190”, “unit”: “A”},
“data set”: {“address”: “16.7”, “value”: “000.42”, “unit”: “kW”},
“data set”: {“address”: “C.7.0”, “value”: “0002”, “unit”: “”},
“data set”: {“address”: “C.5.0”, “value”: “0401”, “unit”: “”},
“data set”: {“address”: “0.2.0”, “value”: “M27”, “unit”: “”}
}
}
}
2019-03-16 12:20:13.434 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=F.F, value=00, unit=null]
2019-03-16 12:20:13.454 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=C.1.0, value=16261281, unit=null]
2019-03-16 12:20:13.462 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=0.0, value=16261281 , unit=null]
2019-03-16 12:20:13.471 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=C.1.1, value= , unit=null]
2019-03-16 12:20:13.479 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=1.8.1, value=007921.472, unit=kWh]
2019-03-16 12:20:13.489 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=1.8.2, value=000000.000, unit=kWh]
2019-03-16 12:20:13.498 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=1.8.3, value=000000.000, unit=kWh]
2019-03-16 12:20:13.506 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=1.8.4, value=000000.000, unit=kWh]
2019-03-16 12:20:13.515 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=1.8.0, value=007921.472, unit=kWh]
2019-03-16 12:20:13.566 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=2.8.0, value=000000.000, unit=kWh]
2019-03-16 12:20:13.576 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=15.8.0, value=007921.472, unit=kWh]
2019-03-16 12:20:13.601 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=32.7, value=229, unit=V]
2019-03-16 12:20:13.607 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=52.7, value=227, unit=V]
2019-03-16 12:20:13.613 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=72.7, value=230, unit=V]
2019-03-16 12:20:13.618 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=31.7, value=00.462, unit=A]
2019-03-16 12:20:13.624 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=51.7, value=00.444, unit=A]
2019-03-16 12:20:13.629 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=71.7, value=01.190, unit=A]
2019-03-16 12:20:13.635 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=16.7, value=000.42, unit=kW]
2019-03-16 12:20:13.640 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=C.7.0, value=0002, unit=null]
2019-03-16 12:20:13.645 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=C.5.0, value=0401, unit=null]
2019-03-16 12:20:13.650 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=0.2.0, value=M27, unit=null]
2019-03-16 12:20:36.854 [DEBUG] [.iec62056.Iec62056_21SerialConnector] - Datamessage read: {
“data message”: {
“manufacturer ID”: “LGZ”,
“meter ID”: “ZMF100AC.M27”,
“enhanced ID/capability”: “”,
“data block”: {
“data set”: {“address”: “F.F”, “value”: “00”, “unit”: “”},
and so on…

msteigenberger · March 16, 2019, 12:44pm

Interesting… Then lets try to narrow it down.
Can you please try the following version of the binding? It has disabled the retry behavior (will now always reconnect) and a stacktrace logging in case it fails (only for debug enabled):
https://drive.google.com/file/d/1oHExOb5O2H_y59lXmXp3KQi6nDeE069D/view?usp=sharing

Can you please try that and then attach a log again (would be good to have it as complete as possible).

greenoid · March 16, 2019, 2:00pm

I copied your 2.5.0-SNAPSHOT in the AddOns folder. But versions do not match:
I guess it has dependencies on 2.5.0-SNAPSHOT, but only 2.4.0 modules are present.

2019-03-16 14:53:27.598 [ERROR] [org.openhab.binding.smartmeter ] - FrameworkEvent ERROR - org.openhab.binding.smartmeter
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.smartmeter [216]
Another singleton bundle selected: osgi.identity; type=“osgi.bundle”; version:Version=“2.4.0”; osgi.identity=“org.openhab.binding.smartmeter”; singleton:=“true”

    at org.eclipse.osgi.container.Module.start(Module.java:444) ~[?:?]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) ~[?:?]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1614) ~[?:?]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) ~[?:?]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) ~[?:?]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[?:?]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
    at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]

greenoid · March 16, 2019, 2:40pm

I tried setting the Version in the MANIFEST.MF to 2.4.0.1 and 2.4.0, but I could not get it to override the build in binding. And I didn’t find the binding anywhere to replace it.

I use Openhabian with openhab2 as a debian package.

Maybe some Apache Karaf override feature magic?

msteigenberger · March 16, 2019, 3:13pm

You need to first uninstall the other bundle (2.4.0) either via paper UI or via karaf bundle:uninstall <ID>

greenoid · March 17, 2019, 1:30pm

I successfully installed your 2.5.0-SNAPSHOT binding.
I set the log to trace.
I installed the serial binding “binding-serial1 - 1.13.0”.
And I configured the serial ports as extra options:
EXTRA_JAVA_OPTS="-Xms250m -Xmx350m -Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB:/dev/ttyAMA0"

Most of the time it seems to work but attached are two logfiles where at some time the reading fails and I don’t know why and when. I tried to provoke it but I got no direct cause. I played around with the Paper UI.

Attached are the two logfiles.
openhab_2.5.0.0.log (72.2 KB)
openhab_2.5.0.1.log (119.5 KB)

msteigenberger · March 17, 2019, 4:52pm

This seems quite good now. Problem is following:
The reading takes around ~3-5 seconds in your case. There is a timeout at 5 seconds. There are cases where it takes longer than the 5 seconds and therefore a timeout occurs (which recovers, hence there is no problem in that).
I now increased the timeout and additionally used a Buffering stream. Can you please test this one and attach logs? (Disclaimer: Sorry if its not working, I have no Hardware to test iec62056).

https://drive.google.com/file/d/12HeZC1ZqHFh_EAdgaFk34_vcc0alKzZ7/view?usp=sharing