search

openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.56k forks source link

[smartmeter] Binding causes openHAB to crash #4472

Closed dominikbenner closed 5 years ago

dominikbenner commented 5 years ago

I’ve installed openhab 2.4 stable.

When i define a sml reader thing (smartmeter 2.4 binding) my complete openhab crashes and restarts itself. This happens as long as the thing exists (openhab start -> 30 seconds -> openhab restart). When i delete the smartmeter sml thing everything is fine.

I went back and deleted the new smartmeter binding and installed a jar for openhab 2.3 from marketplace smartmeter binding -> Everything runs smooth with this.

Current Behavior

2018-12-29 17:33:13.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:23055963
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) [240:org.openhab.binding.smartmeter:2.4.0]
    at io.reactivex.internal.operators.flowable.FlowableTimeoutTimed$TimeoutTask.run(FlowableTimeoutTimed.java:170) [240:org.openhab.binding.smartmeter:2.4.0]
    at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker$BooleanRunnable.run(ExecutorScheduler.java:260) [240:org.openhab.binding.smartmeter:2.4.0]
    at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker.run(ExecutorScheduler.java:225) [240:org.openhab.binding.smartmeter:2.4.0]
    at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [?:?]
    at java.util.concurrent.FutureTask.run(Unknown Source) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?]
    at java.lang.Thread.run(Unknown Source) [?:?]
2018-12-29 17:33:27.620 [WARN ] [org.apache.felix.fileinstall        ] - \usr\share\openhab2\addons does not exist, please create it.
2018-12-29 17:33:27.642 [WARN ] [org.apache.felix.fileinstall        ] - Root path does not exist: E:\usr\share\openhab2\addons
2018-12-29 17:33:31.799 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-12-29 17:33:35.320 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Berlin'.

Steps to Reproduce (for Bugs)

  1. Create new Smartmeter thing

Your Environment

msteigenberger commented 5 years ago

@s4ndst0rm: This rather sounds like an native issue with nrjavaserial. Can you please provide some more information:

dominikbenner commented 5 years ago

@msteigenberger

hs_err_pid11596.log hs_err_pid17636.log

Protocol is SML

java version "1.8.0_162" Java(TM) SE Runtime Environment (build 1.8.0_162-b12) Java HotSpot(TM) 64-Bit Server VM (build 25.162-b12, mixed mode)

openhab.log

melvinisken commented 5 years ago

I get the same problem with openhabian on a RPi 3, openHAB 2.4.0-1, standard binding config (nothing changed except serial port). 

openjdk version "1.8.0_152"
OpenJDK Runtime Environment (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 1.8.0_152-b76)
OpenJDK Client VM (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 25.152-b76, mixed mode, Evaluation)
msteigenberger commented 5 years ago

@s4ndst0rm: It seems you have also installed the old "meterreader" binding. I can see, that this one is reading out values from your device:

2019-01-03 17:54:39.200 [INFO ] [ing.meterreader.internal.MeterDevice] - Read out following values: Device: meterreader:meter:962361ab
Obis: 1-0:1.8.1 MeterValue [obis=1-0:1.8.1, value=1.6720518600000001E7, unit=WATT_HOUR]
Obis: 1-0:16.7.0 MeterValue [obis=1-0:16.7.0, value=2042.1000000000001, unit=WATT]
Obis: 1-0:1.8.2 MeterValue [obis=1-0:1.8.2, value=0.0, unit=WATT_HOUR]
Obis: 129-129:199.130.5 MeterValue [obis=129-129:199.130.5, value=AA A7 CC 39 96 0E 76 F1 BC 39 BF 20 38 5C 70 6B 75 C1 67 6C F8 93 5A EE 9C C4 7A 6F D4 E8 DB 94 77 09 92 A7 BA B5 28 16 8B DC A3 AA 00 68 F4 C6, unit=EMPTY]
Obis: 129-129:199.130.3 MeterValue [obis=129-129:199.130.3, value=45 4D 48, unit=EMPTY]
Obis: 1-0:0.0.9 MeterValue [obis=1-0:0.0.9, value=09 01 45 4D 48 00 00 53 89 E7, unit=EMPTY]
Obis: 1-0:1.8.0 MeterValue [obis=1-0:1.8.0, value=1.6720518600000001E7, unit=WATT_HOUR]

Can you please uninstall this binding (e.g. with the karaf console). Furthermore it would be good if you could enable debug logging for org.eclipse.smarthome.io.transport.serial and attach the openhab.log again.

@melvinisken: Can you please also attach a log file?

dominikbenner commented 5 years ago

@msteigenberger: uninstalled the old binding; logfiles attached openhab.log hs_err_pid17496.log

msteigenberger commented 5 years ago

This is an issue with nrjavaserial. I assume it would work with the old 3.14 version of openhab 2.3. Can you please check which version(s) are installed and running with bundle:list? It seems OH 2.4 installed two versions (3.14.0 and 3.15.0.OH2). If this is the case for you, please try to uninstall 3.15.0.OH2

dominikbenner commented 5 years ago

@msteigenberger there were two nrjavaserial bundles. ive uninstalled the 3.15.0.OH2 bundle. now i get:

2019-01-05 15:03:52.045 [WARN ] [ding.smartmeter.internal.MeterDevice] - Failed to read: No provider for port COM5 found. Closing connection and trying again in 2 seconds...; smartmeter:meter:3a7a2c11

But OH stopped crashing...

When i use 3.15.0.OH2 only it keeps crashing. The old 2.3 binding works with 3.15.0.OH2

msteigenberger commented 5 years ago

Just read your initial comment again. Is it that you have the same openhab 2.4 running with an old version of the smartmeter (meterreader) binding running but the newer version of the binding is not running?

dominikbenner commented 5 years ago

Yes. The old version (meter reader 2.3 from market) runs fine in OH 2.4 with serial 3.15.0OH2. The new smart meter 2.4 binding does not work.

msteigenberger commented 5 years ago

This seems to be rather strange... There was no change in how the data is read out. The crash happens at nrjavaserial side while waiting for data packets from the serial port. Is there any other binding accessing the serial port installed? Can you provide a list of all installed bundles (bundle:list) here?

melvinisken commented 5 years ago

I will try to get the logs soon. I definitely have another binding using serial, the plugwise binding using an usb stick. Additionally, I use remapping from ttyUSB0/1 etc. because it changes every reboot. This caused some issues in the past, at least I often can't select devices like /dev/myowndevicename in PaperUI because it only shows ttyUSB0/1 (they are existing but I don't want to use them because I have to check every restart).

dominikbenner commented 5 years ago

I have the Openhab serial binding installed. It seems that the old meterreader or the new smartmeter binding automatically installs the nrjavaserial 3.14. So in my bundles there are 3.14 and 3.15 again.

bundles.txt

msteigenberger commented 5 years ago

I've looked into the changes done between your working version and now. I found two differences with respect to serial port settings: FlowControl modes and receiveTimeout setting. I've added this two settings and created a PR. Please try out that version and give feedback. Thanks!

dominikbenner commented 5 years ago

How do i get the jar file ?

msteigenberger commented 5 years ago

It's available through the marketplace or here: https://openhab.jfrog.io/openhab/libs-pullrequest-local/org/openhab/binding/org.openhab.binding.smartmeter/2.5.0-SNAPSHOT/org.openhab.binding.smartmeter-2.5.0-SNAPSHOT.jar

dominikbenner commented 5 years ago

The binding gets one response from the serial port but then OH chrashes again. here is the log (last crash was pid 11832) openhab.log hs_err_pid13948.log hs_err_pid19192.log hs_err_pid18488.log hs_err_pid11832.log

msteigenberger commented 5 years ago

Can you please try this one for debugging purposes (don't expect it to work, but have included a debug output at a relevant place I'd like to know): https://drive.google.com/file/d/12gA-__z8nqV0PEcXweDfODT_m5xZiTrG/view?usp=sharing

dominikbenner commented 5 years ago

Heres the log:

openhab.log.txt

msteigenberger commented 5 years ago

Great! Found the issue: It is really a timeout as it takes huge amount of time to consume the device buffer in your case. Probably using a buffered stream fixes the issue! Please test the new jar: https://drive.google.com/file/d/1pRea0uSSS3QYfUB0ug3WGfqiS-PPAS1n/view?usp=sharing

dominikbenner commented 5 years ago

@msteigenberger: Thank you! That solved the issue! (Tested for 10 Minutes without crash)

msteigenberger commented 5 years ago

@s4ndst0rm: thanks for confirmation and the good bug report with your support.

@melvinisken: can you please also verify if it's working for you now?

melvinisken commented 5 years ago

Sorry for beeing unresponsive, I was travelling and had no time to check back. I can verify that openhab doesn't crash anymore with the bundle from google drive. Anyhow, it still doesn't work for me: I have an Easymeter Q3D which provides serial data with 7E1 not 8N1 as it seems to be hardcoded in the bundle. I would really appreciate if you could change this setting to a user defined parameter. (I would try to change this setting myself to test if this is really my issue, but I don't know how to create a bundle out of the sources :-) )

msteigenberger commented 5 years ago

It seems your meter is supporting IEC62051-21 protocol mode D. Can you please try to configure the binding like this? (this mode is not well tested)

melvinisken commented 5 years ago

What makes you think that? I didn't find any information exceeding the comment "uses DIN EN 62056-21 und DIN EN 62056-61 compliant D0-communication port". As I understood, mode D needs some push-method, but the meter is sending its information continously. I can directly connect to the serial port (e.g. via minicom) and see the information in clear text comming every few seconds. (I use the Volkszaehler infrared-USB adaptor, http://wiki.volkszaehler.org/hardware/controllers/ir-schreib-lesekopf-usb-ausgang) Currently, I use easymeter to read out the values and pass them to openHAB (https://github.com/jschanz/easymeter), that works fine. Here is my config for easymeter: `

logger device (e.g. /dev/ttyUSB0)

device = /dev/smartmeter device_baudrate = 9600 device_databits = 7 device_stopbits = 1 device_parity = even Before, I was using the volkszaehler software, which was also working fine. Just to test, I changed the mode of smartmeter to "D". This makes openHAB crash and reboot again. Before, I get a lot of messages like: [WARN ] [.iec62056.Iec62056_21SerialConnector] - Exception while listening for mode D data message java.io.IOException: Received unexpected identification message start byte: 53 at org.openmuc.j62056.internal.IdentificationMessage.(IdentificationMessage.java:49) ~[261:org.openhab.binding.smartmeter:2.5.0.201901101929] at org.openmuc.j62056.Iec21Port$ModeDReceiver.run(Iec21Port.java:70) [261:org.openhab.binding.smartmeter:2.5.0.201901101929]` The start byte changes everytime.

Edit: I'm sorry, I don't geht the comment-feature to take my carriage returns.. it's a little hard to read.

msteigenberger commented 5 years ago

What makes you think that?

It uses 62056-21 protocol which sends periodically -> push which can only happen in mode D.

We already got the Q3D working with mode D. @Marcello87: can you please provide information whether this is still working for you? https://community.openhab.org/t/sml-reader-how-to-integrate/20206/78 https://community.openhab.org/t/sml-reader-how-to-integrate/20206/85

melvinisken commented 5 years ago

Ah, ok. I thought it the other way around - the client has to push to make the device send something (bidirectional, which the Q3D is not). Then it makes sense. I will try again if enabling mode D makes openHAB crash instantly.

melvinisken commented 5 years ago

So, good news, it's running now. I don't know what caused the crash before, but now it's not crashing any more. Maybe it needed the reboot to run correctly. So using mode D I get values now. I had some errors in the log but I don't know if they are related to this binding, I had no time to check in detail. So sorry for bothering.

Marcello87 commented 5 years ago

Hi, sorry i could not answer sooner.

Q3D run's without problems with Mode D in my config, no errors or warnings.

Don't know if it is still of interest but here is my config from the smart meter binding: Port: /dev/ttyUSB0 Refresh Rate: 20 Delay of baudrate change: 0 Baudrate: 9600 Protocol mode: D Conform to specific standard semantics: NONE

Good luck.

melvinisken commented 5 years ago

A quick update: at my setup, the binding still causes a lot of issues. My last message was wrong. The binding was running once, getting all values correct but did not update them any more. I did some tests then and deactivated the binding because I didn't get any results. Today I tried it again using Marcellos settings (in the meantime I also updated to openHAB 2.5.0.M1 Milestone Build) and it only works if I don't change the refresh rate. So if the rate is set on 10s, the binding is running, but in the log I get updates every second (so the rate seems to be ignored). If I change the rate, it stops updating the values and either produces the error messages ("exception while listening..") I posted above or makes openHAB restart. Most of the time openHAB crashes.

edit: I can also provide the openhab.log from tonight but I would prefer to do it via mail and not post it publicly..

msteigenberger commented 5 years ago

So if the rate is set on 10s, the binding is running, but in the log I get updates every second (so the rate seems to be ignored)

Yes, the refresh rate is ignored for the Mode D as it is handled by the j62056 library which doesn't support it.

only works if I don't change the refresh rate. So if the rate is set on 10s

As said: The refresh rate is ignored completely. Should not make any difference.

I can also provide the openhab.log from tonight but I would prefer to do it via mail and not post it publicly..

Yes, please send it via mail to me.

ReelHiJacker commented 4 years ago

Hi everybody, i still have a major problem with the smartmeter binding. I've got a Logarex LK13BE smartmeter and it uses PUSH Mode (Mode D) with 9600bps. I've got a infrared USB reader plugged in my Pi with OpenHAB v2.4. When i test it with cat /dev/ttyUSB0 i receive the messages from the smartmeter. Also the serial binding in OH works and i get data. So i tried the smartmeter binding an didn't get it to work.

When i use cat /dev/ttyUSB0 i receive this message ever second:

/LOG5LK13BE803039

 1-0:96.1.0*255(001LOG0065037599)
 1-0:1.8.0*255(006414.3852*kWh)
 1-0:2.8.0*255(000000.0000*kWh)
 1-0:16.7.0*255(000570*W)
 1-0:32.7.0*255(238.2*V)
 1-0:52.7.0*255(238.9*V)
 1-0:72.7.0*255(238.3*V)
 1-0:31.7.0*255(002.31*A)
 1-0:51.7.0*255(001.10*A)
 1-0:71.7.0*255(000.89*A)
 1-0:81.7.1*255(119*deg)
 1-0:81.7.2*255(238*deg)
 1-0:81.7.4*255(057*deg)
 1-0:81.7.15*255(060*deg)
 1-0:81.7.26*255(047*deg)
 1-0:14.7.0*255(50.0*Hz)
 1-0:1.8.0*96(00021.8*kWh)
 1-0:1.8.0*97(00130.6*kWh)
 1-0:1.8.0*98(00530.5*kWh)
 1-0:1.8.0*99(06365.4*kWh)
 1-0:1.8.0*100(06414.3*kWh)
 1-0:0.2.0*255(ver.03,432F,20170504)
 1-0:96.90.2*255(0F66)
 1-0:97.97.0*255(00000000)
 !

So this seems fine. Here is my smartmeter config:

smartmeter:meter:strom     [port="/dev/ttyUSB0", mode="D", baudrate="9600", refresh=10, baudRateChangeDelay=0] {
    Channels:
        Type 1-0_1-8-0_255 : 1-0_1-8-0_255
}

And here is the error message i received every second:

2019-07-07 08:51:12.349 [WARN ] [.iec62056.Iec62056_21SerialConnector] - Exception while listening for mode D data message
java.io.IOException: Received unexpected identification message start byte: 00
    at org.openmuc.j62056.internal.IdentificationMessage.<init>(IdentificationMessage.java:49) ~[254:org.openhab.binding.smartmeter:2.5.0.201904261421]
    at org.openmuc.j62056.Iec21Port$ModeDReceiver.run(Iec21Port.java:70) [254:org.openhab.binding.smartmeter:2.5.0.201904261421]

I tried the v2.4.0 and your new v2.5.0 you posted above. Same problem. So this seems to be the same like @melvinisken have... So i looked into the j62056 library and it seems that it didn't get the right identification message (IdentificationMessage.java / Line 49 - it expects a / and didn't get that) ... do you have an idea whats the problem? For me it looks like it didn't get the serial data right but i don't know what to do... (i already tried restart several times, different parameters in binding config and so on..)

So i tried a workaround with serial binding and rules (https://community.openhab.org/t/using-a-power-meter-sml-with-openhab/21923/18) this works but my openhab log explodes because it gets every second the complete smartmeter data plus the other stuff. So it would be great if the smartmeter binding would work also because i've got a second smartmeter which i also will bring into openhab...

ReelHiJacker commented 4 years ago

So, now it works. I've sort it out: After i saved the .things config of the smartmeter binding i have to set stty -F /dev/ttyUSB0 raw ... so i have to change the serial port to "RAW" ... but i have to do this on every restart and every save of the things file

So, now i'm stuck with this... Can anybody please help me?

KarstenB commented 4 years ago

Leaving this here for some other people to find. I had some issues with the Logarex LK13BE as well, and it appears that it doesn't do parity as it is supposed to do. So when the smartmeter binding is requesting 7 bits with even parity, it fails a few bytes, which are silently dropped in the low-level driver. This causes invalid syncs and invalid data.... and potentially crashing openhab (I didn't manage to get smartmeter to detect mine as well).

Marcello87 commented 3 years ago

Hi, since a few months my binding only works for a few minutes than it stop working.

Someone with the same bug or with an hint? Updates (now 2.5.7) / reboots / reconfigure don't work.

My log: `2020-07-29 22:32:02.256 [ERROR] [ding.smartmeter.internal.MeterDevice] - Meter listener failed java.lang.IllegalArgumentException: ID segment '�-_0-0-0255' contains invalid characters. Each segment of the ID must match the pattern [A-Za-z0-9-]*. at org.eclipse.smarthome.core.common.AbstractUID.validateSegment(AbstractUID.java:97) ~[bundleFile:?] at org.eclipse.smarthome.core.common.AbstractUID.(AbstractUID.java:75) ~[bundleFile:?] at org.eclipse.smarthome.core.common.AbstractUID.(AbstractUID.java:58) ~[bundleFile:?] at org.eclipse.smarthome.core.thing.UID.(UID.java:57) ~[bundleFile:?] at org.eclipse.smarthome.core.thing.type.ChannelTypeUID.(ChannelTypeUID.java:50) ~[bundleFile:?] at org.openhab.binding.smartmeter.internal.SmartMeterChannelTypeProvider.getChannelType(SmartMeterChannelTypeProvider.java:91) ~[bundleFile:?] at org.openhab.binding.smartmeter.internal.SmartMeterChannelTypeProvider.valueChanged(SmartMeterChannelTypeProvider.java:74) ~[bundleFile:?]

... at io.reactivex.internal.operators.flowable.FlowableCreate$NoOverflowBaseAsyncEmitter.onNext(FlowableCreate.java:403) [bundleFile:?] at org.openhab.binding.smartmeter.internal.iec62056.Iec62056_21SerialConnector$1.newDataMessage(Iec62056_21SerialConnector.java:103) [bundleFile:?] at org.openmuc.j62056.Iec21Port$ModeDReceiver.run(Iec21Port.java:71) [bundleFile:?]`