DSMR Smartmeter (beta) [3.2.0;4.0.0)

Add-on Marketplace Bundles
, ,
1

This beta DSMR beta release (supports openHAB 3.2.0 and above) intends to improve feedback given by the binding when the data from the meter can’t be correctly read. When the data can’t be read correctly, for example due to incorrect P1 cables, the binding now tries to better give feedback.

Install this version if you have problems getting things discovered or have problems reading data from the meter. Otherwise just install the official DSMR binding.

NOTE: The binding depends on the serial transport bundle. The binding provided here is a jar file, and than that bundle isn’t automatically loaded. This could have been done by providing a .kar file, but that is always very openHAB version specific, and the market place doesn’t support multiple versions. Therefor to get this version working you need to install another binding that also uses the serial bundle, like the serial binding. Or it just should work if you already have such binding installed (That must not be the official version of the DSMR binding, you need to uninstall it before installing this version.)

Changelog

Version (03-02-2023-3) (also available in 4.0.0.M1 and later)

  • Fixed incorrect additional key initialization in discovery service.
  • Some additional improvements to not set thing directly off line when temporary read problems happen.

Version (27-01-2023)

  • Several stability improvements:
    • Additional checks on validity of smarty decryption tokens.
    • Made handling corrupted data more lenient by not setting the thing to offline every time a corrupt telegram is received, but let the watchdog handle this.

Version (20-11-2022)

  • Added safeguard against buffer overflows in reading data in SmartyDecryptor.

Version (09-11-2022)

  • Improve reporting on inability parse data
  • Fixes nullpointer exception that can happen when corrupt data is read.

Resources

org.openhab.binding.dsmr-4.0.0-SNAPSHOT.jar

Changes PR 14325

2

Hi @hilbrand!

I recently spotted problems with the bridge thing going offline from time to time (COMMUNICATION_ERROR - Not receiving data from meter.). In the logs i found many of the following messages:

2022-12-21 13:39:01.494 [WARN ] [device.connector.DSMRSerialConnector] - RuntimeException during handling serial event: 1
java.nio.BufferOverflowException: null
        at java.nio.Buffer.nextPutIndex(Buffer.java:666) ~[?:?]
        at java.nio.HeapByteBuffer.put(HeapByteBuffer.java:200) ~[?:?]
        at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.processStateActions(SmartyDecrypter.java:129) ~[bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.parse(SmartyDecrypter.java:106) ~[bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.DSMRTelegramListener.handleData(DSMRTelegramListener.java:75) ~[bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.connector.DSMRBaseConnector.handleDataAvailable(DSMRBaseConnector.java:116) ~[bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.connector.DSMRSerialConnector.handleDataAvailable(DSMRSerialConnector.java:317) ~[bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.connector.DSMRSerialConnector.serialEvent(DSMRSerialConnector.java:276) [bundleFile:?]
        at org.openhab.core.io.transport.serial.rxtx.RxTxSerialPort$1.serialEvent(RxTxSerialPort.java:82) [bundleFile:?]
        at gnu.io.RXTXPort.sendEvent(RXTXPort.java:834) ~[bundleFile:5.2.1.OH1]
        at gnu.io.RXTXPort.eventLoop(Native Method) [bundleFile:5.2.1.OH1]
        at gnu.io.RXTXPort$MonitorThread.run(RXTXPort.java:108) [bundleFile:5.2.1.OH1]

Is this also targeted in your beta release? When are you planning to release this improvements?

I also think that this problem is caused by the physical layer, as I changed my cabling recently. But as disabling and enabling the bridge thing solves this problem, I think it should be possible to handle this case of problem within the bundle?!?

Thanks a lot,

MW

3

Yes this should be handled by the beta version. It can happen due to cable problems, when corrupt data is read the parser gets confused and gets into a state that can cause this bug.

The changes will be added to the main official binding, I just haven’t had time to make a pull request as I also wanted to check if it works ok since there are a number of small changes to make it more robust against bad input.

4

And another error I see sometimes bringing the thing offline for a short period of time:

2022-12-29 23:10:06.486 [WARN ] [dsmr.internal.device.SmartyDecrypter] - Decrypting smarty telegram failed:
javax.crypto.AEADBadTagException: Tag mismatch!
        at com.sun.crypto.provider.GaloisCounterMode.decryptFinal(GaloisCounterMode.java:623) ~[?:?]
        at com.sun.crypto.provider.CipherCore.finalNoPadding(CipherCore.java:1116) ~[?:?]
        at com.sun.crypto.provider.CipherCore.fillOutputBuffer(CipherCore.java:1053) ~[?:?]
        at com.sun.crypto.provider.CipherCore.doFinal(CipherCore.java:853) ~[?:?]
        at com.sun.crypto.provider.AESCipher.engineDoFinal(AESCipher.java:446) ~[?:?]
        at javax.crypto.Cipher.doFinal(Cipher.java:2260) ~[?:?]
        at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.decrypt(SmartyDecrypter.java:217) [bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.processCompleted(SmartyDecrypter.java:194) [bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.parse(SmartyDecrypter.java:107) [bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.DSMRTelegramListener.handleData(DSMRTelegramListener.java:75) [bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.connector.DSMRBaseConnector.handleDataAvailable(DSMRBaseConnector.java:116) [bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.connector.DSMRSerialConnector.handleDataAvailable(DSMRSerialConnector.java:317) [bundleFile:?]
        at org.openhab.binding.dsmr.internal.device.connector.DSMRSerialConnector.serialEvent(DSMRSerialConnector.java:276) [bundleFile:?]
        at org.openhab.core.io.transport.serial.rxtx.RxTxSerialPort$1.serialEvent(RxTxSerialPort.java:82) [bundleFile:?]
        at gnu.io.RXTXPort.sendEvent(RXTXPort.java:834) ~[bundleFile:5.2.1.OH1]
        at gnu.io.RXTXPort.eventLoop(Native Method) [bundleFile:5.2.1.OH1]
        at gnu.io.RXTXPort$MonitorThread.run(RXTXPort.java:108) [bundleFile:5.2.1.OH1]

Maybe this is also related?

BR

5

Yes that can be related. Corrupt data means just some bits are flipped. With encrypted data the binding doesn’t know if the data is corrupt or if the key is simply incorrect. So Im looking into better ways to handle this. For example if a previous message could be decrypted it is more likely the data is corrupt instead of an invalid key. That could guide the binding to better handle such cases.

1 Like
6

Perfect.
I just installed the beta version and will report any changes…

1 Like
7

Hi @hilbrand!
Result from 1 week with the beta binding:
Errors in the log are gone, but the bridge thing goes offline for a very short period of time very often (20-30 times a day), but immediatly comes online again.

In the logs I just see the following entry, related to one item linked to the dsmr binding:

2023-01-06 09:14:57.787 [WARN ] [rnal.defaultscope.ScriptBusEventImpl] - Command 'NaN' cannot be parsed for item 'Strom_Haupt_ActUsage (Type=NumberItem, State=34 W, Label=Aktueller Strombezug netto, Category=null, Tags=[Measurement, Power], Groups=[gPowerMeter_Grid, gMeterActual])'.

This item is a proxy item which gets calculated through a JS rule the following way:

var calcValue = items.getItem("Strom_Haupt_PowConsumed").rawState - items.getItem("Strom_Haupt_PowReturned").rawState;
items.getItem("Strom_Haupt_ActUsage").sendCommand(calcValue);

with this item definitions:

Number:Power				Strom_Haupt_PowConsumed				"Aktueller Strombezug [%f W]"										(gPowerMeter_Grid, gMeterActual)			["Measurement","Power"]		{channel="dsmr:electricity_smarty_v1_0_austria:smartMeter:dsmr0:emeter_actual_delivery"}
Number:Power				Strom_Haupt_PowReturned				"Aktuelle Stromlieferung [%f W]"									(gPowerMeter_Grid, gMeterActual)			["Measurement","Power"]		{channel="dsmr:electricity_smarty_v1_0_austria:smartMeter:dsmr0:emeter_actual_production"}
Number:Power				Strom_Haupt_ActUsage				"Aktueller Strombezug netto [%f W]"									(gPowerMeter_Grid, gMeterActual)			["Measurement","Power"]

So, my interpretation:
Thing goes offline, the linked channels get NaN values in this moment before the thing comes online again and everything is running.
I try to discard this NaN values in my rule, so I should’nt have any errors in the logs. But the offline/online toggling seems to stay for the moment.

Do you need any further logging details? I could change the loglevel somewhere to get you more details?!?

BR

8

Likely it can’t parse the data. In such case it sets it to offline. If the next telegram is valid (and it updates every 10 seconds) it will set thing back to online. You can set log level to debug to see if it logs an error. Also I’m going to look into how to make the binding a bit more resilient against sometimes receiving bad data.

9

OK. I’ll get some debug log-data this evening.

Just one question/solution in my opinion: Could it be a solution (regarding resilience) to set the Thing offline if more than x telegrams could not be parsed correctly (some parameter in the configuration), or if no valid telegram is received during a specific amount of time?

BR

10

There is already an configuration option to set the thing offline if no data is received after a number of seconds (receivedTimeout). But that doesn’t take into account if it does receive data, but the data is invalid. So it might be an idea to enhance this with an extra check if no data valid was received.

11

Error messages as following (with log level DEBUG):

2023-01-10 20:46:53.239 [WARN ] [dsmr.internal.device.SmartyDecrypter] - Failed encrypted telegram: 4F9F91C4C785F15DBDD933982038F009696794628EC1CEC04F202322365A551ABF3AA054B20CA7545C541CD77A935D6E18AEE1104339CFD11BAE33031354806BDC2979B170FD900C84FC41B46D83A08421D740D91323D5018D2715DE820091D20558DB9168432F519E7B2DEEC40F14FE8624371BD2085CFAED87F2B255013A8241A926393B59FBA83AA91BDEE15130D98A1A27298F26149193FF08D1D9465B902D86E6885695D5C3EE9C5C63582B89D26CF71E661F7C1D7821ECF2C695E71544C87F12B1EDD6C9CBC98E9BC419A522A88B56461171561067E0B8C34414712012D294127293F5FBFACD9FFAB8B210FDFEBF47A9A1F216BAA8079E72C0F975A45314B37673E0343222178C32CDF58D9D993BE2F57FD8656D962EEB5CD79237C06D47153FF155C19E463A2DA90E0A37135432C74036248AEF1C24E6E0597D09C9B0397D588115C49015E01DA151FF97A9C2411EF92D678FC1CA59E7BC0D4CB2836C016A50536F46F185A36822EDFAE37592BD33C0107AEC8C9EAC4A43E7AC0EF324F837A7ECF5DA4B15A41B58DEB8E2E65E01F97FEBE4F9309223470AAC35BEF5C5CBC0F9C107A6819EB314BDD3FEF8E8B215550D1D752D08A57F924A82EAC4A9E4A6B2276A1ACAD2E8E4F8CBCABF67104316CA68A80D90B37D0FD9EC1A686F3EE7417930D1DC77486874D0782C6A
2023-01-10 20:46:53.243 [WARN ] [dsmr.internal.device.SmartyDecrypter] - Exception of failed decryption of telegram: 
javax.crypto.AEADBadTagException: Tag mismatch!
	at com.sun.crypto.provider.GaloisCounterMode.decryptFinal(GaloisCounterMode.java:623) ~[?:?]
	at com.sun.crypto.provider.CipherCore.finalNoPadding(CipherCore.java:1116) ~[?:?]
	at com.sun.crypto.provider.CipherCore.fillOutputBuffer(CipherCore.java:1053) ~[?:?]
	at com.sun.crypto.provider.CipherCore.doFinal(CipherCore.java:853) ~[?:?]
	at com.sun.crypto.provider.AESCipher.engineDoFinal(AESCipher.java:446) ~[?:?]
	at javax.crypto.Cipher.doFinal(Cipher.java:2260) ~[?:?]
	at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.decrypt(SmartyDecrypter.java:218) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.processCompleted(SmartyDecrypter.java:196) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.parse(SmartyDecrypter.java:106) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.DSMRTelegramListener.handleData(DSMRTelegramListener.java:74) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.connector.DSMRBaseConnector.handleDataAvailable(DSMRBaseConnector.java:117) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.connector.DSMRSerialConnector.handleDataAvailable(DSMRSerialConnector.java:319) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.connector.DSMRSerialConnector.serialEvent(DSMRSerialConnector.java:278) [bundleFile:?]
	at org.openhab.core.io.transport.serial.rxtx.RxTxSerialPort$1.serialEvent(RxTxSerialPort.java:82) [bundleFile:?]
	at gnu.io.RXTXPort.sendEvent(RXTXPort.java:834) ~[bundleFile:5.2.1.OH1]
	at gnu.io.RXTXPort.eventLoop(Native Method) [bundleFile:5.2.1.OH1]
	at gnu.io.RXTXPort$MonitorThread.run(RXTXPort.java:108) [bundleFile:5.2.1.OH1]
12

If the AEADBadTagException happens occasionally it’s very likely the data is corrupt and there can’t be decoded.

13

Update (27-01-2023) Updated the marketplace binding with an improved version that should be better at handling bad data.

14

Hello dev team,
tried installing the standard and this beta version but both give the same error log during discovery.
Manual adding gives me a thing which is “Online” but generates no Channels.
Any help appreciated.

2023-02-02 14:10:13.643 [ERROR] [nternal.DiscoveryServiceRegistryImpl] - Cannot trigger scan for thing types '[dsmr:electricity_smarty_v1_0_austria, dsmr:electricity_ace4000, dsmr:generic_v3_0, dsmr:gas_emucs_v1_0, dsmr:m3_v4, dsmr:device_emucs_v1_0, dsmr:gas_ace4000, dsmr:gj_v4, dsmr:device_v2_v3, dsmr:m3_v5_0, dsmr:electricity_smarty_v1_0, dsmr:electricity_emucs_v1_0, dsmr:electricity_v3_0, dsmr:electricity_v2_1, dsmr:electricity_v4_0, dsmr:electricity_v2_2, dsmr:electricity_v4_2, dsmr:water_v2_2, dsmr:electricity_v5_0, dsmr:water_v3_0, dsmr:slave_electricity_v5_0, dsmr:heating_v2_2, dsmr:slave_electricity2_ace4000, dsmr:gj_v3_0, dsmr:gj_v5_0, dsmr:cooling_v2_2, dsmr:gas_v2_2, dsmr:gas_v2_1, dsmr:gas_v3_0, dsmr:water_ace4000, dsmr:device_v5, dsmr:device_v4, dsmr:slave_electricity1_ace4000, dsmr:cooling_ace4000, dsmr:heating_ace4000, dsmr:electricity_v4_0_4, dsmr:slave_electricity_v4]' on 'DSMRBridgeDiscoveryService'!
java.lang.IllegalArgumentException: hexString contains illegal character for hexToBytes: 73
	at org.openhab.core.util.HexUtils.unhex(HexUtils.java:143) ~[?:?]
	at org.openhab.core.util.HexUtils.hexToBytes(HexUtils.java:111) ~[?:?]
	at org.openhab.core.util.HexUtils.hexToBytes(HexUtils.java:123) ~[?:?]
	at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.<init>(SmartyDecrypter.java:97) ~[?:?]
	at org.openhab.binding.dsmr.internal.device.DSMRTelegramListener.<init>(DSMRTelegramListener.java:59) ~[?:?]
	at org.openhab.binding.dsmr.internal.discovery.DSMRBridgeDiscoveryService.lambda$0(DSMRBridgeDiscoveryService.java:134) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195) ~[?:?]
	at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177) ~[?:?]
	at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177) ~[?:?]
	at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655) ~[?:?]
	at java.util.stream.Streams$ConcatSpliterator.forEachRemaining(Streams.java:734) ~[?:?]
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[?:?]
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497) ~[?:?]
	at java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:274) ~[?:?]
	at java.util.HashMap$KeySpliterator.forEachRemaining(HashMap.java:1621) ~[?:?]
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[?:?]
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497) ~[?:?]
	at org.openhab.binding.dsmr.internal.discovery.DSMRBridgeDiscoveryService.startScan(DSMRBridgeDiscoveryService.java:120) ~[?:?]
	at org.openhab.core.config.discovery.AbstractDiscoveryService.startScan(AbstractDiscoveryService.java:195) ~[?:?]
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.startScan(DiscoveryServiceRegistryImpl.java:377) ~[?:?]
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.startScans(DiscoveryServiceRegistryImpl.java:362) ~[?:?]
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.startScan(DiscoveryServiceRegistryImpl.java:211) ~[?:?]
	at org.openhab.core.io.rest.core.internal.discovery.DiscoveryResource.scan(DiscoveryResource.java:105) ~[?:?]
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
	at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:179) ~[bundleFile:3.4.5]
	at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96) ~[bundleFile:3.4.5]
	at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:201) ~[bundleFile:3.4.5]
	at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:104) ~[bundleFile:3.4.5]
	at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) ~[bundleFile:3.4.5]
	at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) ~[bundleFile:3.4.5]
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) ~[bundleFile:3.4.5]
	at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) ~[bundleFile:3.4.5]
	at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:265) ~[bundleFile:3.4.5]
	at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) ~[bundleFile:3.4.5]
	at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) ~[bundleFile:3.4.5]
	at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:160) ~[bundleFile:3.4.5]
	at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:225) ~[bundleFile:3.4.5]
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:298) ~[bundleFile:3.4.5]
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:217) ~[bundleFile:3.4.5]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) ~[bundleFile:3.1.0]
	at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:273) ~[bundleFile:3.4.5]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[bundleFile:9.4.46.v20220331]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:74) ~[bundleFile:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[bundleFile:9.4.46.v20220331]
	at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:294) ~[bundleFile:?]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[bundleFile:9.4.46.v20220331]
	at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:90) ~[bundleFile:?]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.46.v20220331]
	at java.lang.Thread.run(Thread.java:829) [?:?]
15

First of all thx for the great extension! I switched to the BETA version as i got a lot of BufferOverflow errors in the official version. This version seems to be a lot more stable.

I am also observing the same as @mwildbolz. The smartyBridge toggles a lot between OFFLINE and ONLINE because of a tag missmatch error. Would also prefer an option to set the bridge OFFLINE only if it fails to decrypt more than x messages. Setting it OFFLINE immediate is maybe not the best regarding to all items getting NULL during that time.

16

I’ve updated the binding in the market place. There was a bug in the discovery service that caused this. Can you retry?

17

The version in the market place should not set the binding off line on each failed message. If you still see this behavior please report it. The binding online reports it as offline after a set timeout period. This can be configured with receivedTimeout (default 120 seconds). This configuration option is also used when no messages are received after that time period.

18

OK then i am missinterpretieren the logs. When all runs normal then the binding read values once each minute? Is that correct? Or is the smart-meter pushing the values?

==> /var/log/openhab/openhab.log <==

2023-02-03 09:50:04.100 [DEBUG] [mr.internal.handler.DSMRMeterHandler] - Updating state for channel emeter_total_imported_energy_register_r_rate2 to value 391.235 kvarh
2023-02-03 09:50:04.103 [DEBUG] [mr.internal.handler.DSMRMeterHandler] - Updating state for channel emeter_actual_reactive_delivery to value 1482
2023-02-03 09:50:04.104 [DEBUG] [mr.internal.handler.DSMRMeterHandler] - Updating state for channel emeter_total_exported_energy_register_q to value 3513.864 kvarh
2023-02-03 09:50:04.107 [DEBUG] [mr.internal.handler.DSMRMeterHandler] - Updating state for channel emeter_total_exported_energy_register_r_rate1 to value 2037.789 kvarh
2023-02-03 09:50:04.109 [DEBUG] [mr.internal.handler.DSMRMeterHandler] - Updating state for channel emeter_total_exported_energy_register_r_rate2 to value 1476.075 kvarh
2023-02-03 09:50:04.111 [DEBUG] [mr.internal.handler.DSMRMeterHandler] - Updating state for channel emeter_actual_reactive_production to value 0
2023-02-03 09:51:02.678 [WARN ] [dsmr.internal.device.SmartyDecrypter] - Failed encrypted telegram: D88154634B275E64E2B907B05F19C0262FA4007DD3B898207141A1FE9A4280AF64054EAEBE7BCDDD7CF471FEB5F070C72AF144EF636240687CB2DA6A3C9AAD693AFDDE04EDCD777AB87575CE37304F7420F9DFA4A808A33EF90670068DA37BE1A8B2A64421C521B110D55AA7718B0040E82144A4C257F2FF509A15D3B7B03B84B8A89C10281D947874C7F6BB4DB55974CA2606932E4C2F4C2B31A692E4C1296B9BE228E17CF3ED79571D22E9E28204417B933337C476079B286E9758A70421E60EC7377527E4F05D84D5BAD8FBB3DA74F28C9956D26C98271230ECEB58843B309D6B7191FC1978BAF7175EBE89096932AE9159AEB2A7C6CB35A3AA2E7981E38F6896FB0FF5A4163DEAF86B65E5A2B3C65A571DAF9DAD35A1B7DD14FAFF543314B7D42EBCF39E7EAE930FB2EA1D77F6E2DFA32C1E9A10721C01278423D1B82630CE9D5F5826EA4C81641D708EF4CFB81AC2E3AFE0412E94663865AC232D9AA2F9B5C8634874CC347B846A88452CBFC4F728E20A46B00D57AB46F474A2422066AB002B3941DF5E9DA1C530EE828D9844E46228AAEDF1CDEAC3D7DE4AF5E71AF5092ADE74BEF95B607A9D15F0A5F4352D2DB0EAA3D9AFC02CE05617DCAFB14EF428D441F8C014386F7074222AB958E3A39FE90626144E35C21893E76F2F31C1D7BAF4B83CA05D17C8AAC484C8418E
2023-02-03 09:51:02.682 [WARN ] [dsmr.internal.device.SmartyDecrypter] - Exception of failed decryption of telegram: 
javax.crypto.AEADBadTagException: Tag mismatch!
	at com.sun.crypto.provider.GaloisCounterMode.decryptFinal(GaloisCounterMode.java:623) ~[?:?]
	at com.sun.crypto.provider.CipherCore.finalNoPadding(CipherCore.java:1116) ~[?:?]
	at com.sun.crypto.provider.CipherCore.fillOutputBuffer(CipherCore.java:1053) ~[?:?]
	at com.sun.crypto.provider.CipherCore.doFinal(CipherCore.java:853) ~[?:?]
	at com.sun.crypto.provider.AESCipher.engineDoFinal(AESCipher.java:446) ~[?:?]
	at javax.crypto.Cipher.doFinal(Cipher.java:2260) ~[?:?]
	at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.decrypt(SmartyDecrypter.java:218) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.processCompleted(SmartyDecrypter.java:196) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.SmartyDecrypter.parse(SmartyDecrypter.java:106) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.DSMRTelegramListener.handleData(DSMRTelegramListener.java:75) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.connector.DSMRBaseConnector.handleDataAvailable(DSMRBaseConnector.java:117) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.connector.DSMRSerialConnector.handleDataAvailable(DSMRSerialConnector.java:319) [bundleFile:?]
	at org.openhab.binding.dsmr.internal.device.connector.DSMRSerialConnector.serialEvent(DSMRSerialConnector.java:278) [bundleFile:?]
	at org.openhab.core.io.transport.serial.rxtx.RxTxSerialPort$1.serialEvent(RxTxSerialPort.java:82) [bundleFile:?]
	at gnu.io.RXTXPort.sendEvent(RXTXPort.java:834) ~[bundleFile:5.2.1.OH1]
	at gnu.io.RXTXPort.eventLoop(Native Method) [bundleFile:5.2.1.OH1]
	at gnu.io.RXTXPort$MonitorThread.run(RXTXPort.java:108) [bundleFile:5.2.1.OH1]
==> /var/log/openhab/events.log <==

2023-02-03 09:51:02.689 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'dsmr:smartyBridge:4e59490f3c' changed from ONLINE to OFFLINE (CONFIGURATION_ERROR): Failed to decrypt P1 telegram due to invalid encryption key
2023-02-03 09:51:02.696 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'dsmr:electricity_smarty_v1_0_austria:4e59490f3c:0' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2023-02-03 09:51:02.705 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Smart_Meter_LastUpdate' changed from 2023-02-03T09:49:51.000+0100 to NULL
2023-02-03 09:51:02.707 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Smart_Meter_Actual_PowerDelivery' changed from 1.422 kW to NULL
2023-02-03 09:51:02.728 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'dsmr:smartyBridge:4e59490f3c' changed from OFFLINE (CONFIGURATION_ERROR): Failed to decrypt P1 telegram due to invalid encryption key to ONLINE

It reads on message at 09:50:04, the next - one minute later - fails and the bridge is immediately set of offline. Strangely it is set back to online a few milliseconds later :smiley:

Is there any preferred place to report issues? In another thread or in here?

19

Ah that doesn’t look right. I’ve made a small change and updated the binding here (03-02-2023-2). It should not set the device directly off line.

Normally bug reports are best reported at the openHAB-addons GitHub repository. But since this market place binding is also working on fixing this specific issue you can report here.

1 Like
20

That was insanely quick :smiley: I updated to the newest version and the bridge now remained online the last 3 hours. Also i did observe far less tag mismatch errors.

Thx! :star_struck: