While meanwhile the binding is working quite smooth, I still have two problems:
I use openHab 2.3 as service with Win 10. Every two weeks the system performs a restart (after the patchday).
I have then the problem that your binding is not able to connect to the reader until I disconnect the cable for a couple of seconds and reconnect it again. The error message looks like:
2018-09-14 11:46:03.943 [INFO ] [ing.meterreader.internal.MeterDevice] - Opening connection to meterreader:meter:40b47862
2018-09-14 11:46:03.960 [ERROR] [ing.meterreader.internal.MeterDevice] - Failed to read: Error at SerialConnector.openConnection: port COM3 is already in use.. Closing connection and trying again...; meterreader:meter:40b47862
java.io.IOException: Error at SerialConnector.openConnection: port COM3 is already in use.
But there is no other service using this usb connection.
I have every hour the following issue (which recovers itself, but during that time slows down OH):
2018-09-21 07:16:21.130 [INFO ] [ing.meterreader.internal.MeterDevice] - Opening connection to meterreader:meter:40b47862
2018-09-21 07:57:01.304 [WARN ] [ader.internal.sml.SmlSerialConnector] - 1. reading attempt failed: wrong crc. Retrying COM3...
2018-09-21 07:57:01.304 [WARN ] [ader.internal.sml.SmlSerialConnector] - Delaying retry by PT1S
2018-09-21 08:13:02.328 [WARN ] [ader.internal.sml.SmlSerialConnector] - 2. reading attempt failed: wrong crc. Retrying COM3...
2018-09-21 08:13:02.328 [WARN ] [ader.internal.sml.SmlSerialConnector] - Delaying retry by PT2S
2018-09-21 08:20:44.360 [WARN ] [ader.internal.sml.SmlSerialConnector] - 3. reading attempt failed: wrong crc. Retrying COM3...
2018-09-21 08:20:44.360 [WARN ] [ader.internal.sml.SmlSerialConnector] - Delaying retry by PT3S
2018-09-21 08:24:27.384 [ERROR] [ing.meterreader.internal.MeterDevice] - Failed to read: java.io.IOException: wrong crc. Closing connection and trying again...; meterreader:meter:40b47862
java.lang.RuntimeException: java.io.IOException: wrong crc
at com.google.common.base.Throwables.propagate(Throwables.java:160) ~[23:com.google.guava:18.0.0]
at org.openhab.binding.meterreader.connectors.ConnectorBase.lambda$0(ConnectorBase.java:82) ~[208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.functions.Functions$Array2Func.apply(Functions.java:529) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.functions.Functions$Array2Func.apply(Functions.java:516) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableZip$ZipCoordinator.drain(FlowableZip.java:241) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableZip$ZipSubscriber.onNext(FlowableZip.java:383) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.processors.UnicastProcessor.drainFused(UnicastProcessor.java:254) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.processors.UnicastProcessor.drain(UnicastProcessor.java:287) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.processors.UnicastProcessor.onNext(UnicastProcessor.java:349) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.processors.SerializedProcessor.onNext(SerializedProcessor.java:103) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableRepeatWhen$WhenSourceSubscriber.again(FlowableRepeatWhen.java:170) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableRetryWhen$RetryWhenSubscriber.onError(FlowableRetryWhen.java:77) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.checkTerminate(FlowableFlatMap.java:566) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:374) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.innerError(FlowableFlatMap.java:605) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onError(FlowableFlatMap.java:668) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.error(FlowableCreate.java:288) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.tryOnError(FlowableCreate.java:277) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.onError(FlowableCreate.java:270) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual(FlowableCreate.java:75) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.Flowable.subscribe(Flowable.java:14291) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.Flowable.subscribe(Flowable.java:14237) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.onNext(FlowableFlatMap.java:163) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableOnBackpressureDrop$BackpressureDropSubscriber.onNext(FlowableOnBackpressureDrop.java:84) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableBuffer$PublisherBufferExactSubscriber.onNext(FlowableBuffer.java:126) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableInterval$IntervalSubscriber.run(FlowableInterval.java:93) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.schedulers.ScheduledDirectPeriodicTask.run(ScheduledDirectPeriodicTask.java:38) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [?:?]
at java.util.concurrent.FutureTask.runAndReset(Unknown Source) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(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) [?:?]
Caused by: java.io.IOException: wrong crc
at org.openmuc.jsml.transport.MessageExtractor.waitForStopSequence(MessageExtractor.java:113) ~[?:?]
at org.openmuc.jsml.transport.MessageExtractor.getSmlMessage(MessageExtractor.java:42) ~[?:?]
at org.openmuc.jsml.transport.Transport.getSMLFile(Transport.java:101) ~[?:?]
at org.openhab.binding.meterreader.internal.sml.SmlSerialConnector.readNext(SmlSerialConnector.java:73) ~[?:?]
at org.openhab.binding.meterreader.internal.sml.SmlSerialConnector.readNext(SmlSerialConnector.java:1) ~[?:?]
at org.openhab.binding.meterreader.connectors.ConnectorBase.emitValues(ConnectorBase.java:121) ~[?:?]
at org.openhab.binding.meterreader.connectors.ConnectorBase.lambda$2(ConnectorBase.java:98) ~[?:?]
at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual(FlowableCreate.java:72) ~[?:?]
... 14 more
2018-09-21 08:24:27.591 [INFO ] [ing.meterreader.internal.MeterDevice] - Opening connection to meterreader:meter:40b47862
2018-09-21 08:41:07.762 [WARN ] [ader.internal.sml.SmlSerialConnector] - 1. reading attempt failed: wrong crc. Retrying COM3...
2018-09-21 08:41:07.762 [WARN ] [ader.internal.sml.SmlSerialConnector] - Delaying retry by PT1S
2018-09-21 08:48:48.809 [WARN ] [ader.internal.sml.SmlSerialConnector] - 2. reading attempt failed: wrong crc. Retrying COM3...
2018-09-21 08:48:48.809 [WARN ] [ader.internal.sml.SmlSerialConnector] - Delaying retry by PT2S
2018-09-21 08:56:50.827 [WARN ] [ader.internal.sml.SmlSerialConnector] - 3. reading attempt failed: wrong crc. Retrying COM3...
2018-09-21 08:56:50.827 [WARN ] [ader.internal.sml.SmlSerialConnector] - Delaying retry by PT3S
2018-09-21 09:00:53.853 [ERROR] [ing.meterreader.internal.MeterDevice] - Failed to read: java.io.IOException: wrong crc. Closing connection and trying again...; meterreader:meter:40b47862
java.lang.RuntimeException: java.io.IOException: wrong crc
at com.google.common.base.Throwables.propagate(Throwables.java:160) ~[23:com.google.guava:18.0.0]
at org.openhab.binding.meterreader.connectors.ConnectorBase.lambda$0(ConnectorBase.java:82) ~[208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.functions.Functions$Array2Func.apply(Functions.java:529) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.functions.Functions$Array2Func.apply(Functions.java:516) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableZip$ZipCoordinator.drain(FlowableZip.java:241) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableZip$ZipSubscriber.onNext(FlowableZip.java:383) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.processors.UnicastProcessor.drainFused(UnicastProcessor.java:254) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.processors.UnicastProcessor.drain(UnicastProcessor.java:287) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.processors.UnicastProcessor.onNext(UnicastProcessor.java:349) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.processors.SerializedProcessor.onNext(SerializedProcessor.java:103) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableRepeatWhen$WhenSourceSubscriber.again(FlowableRepeatWhen.java:170) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableRetryWhen$RetryWhenSubscriber.onError(FlowableRetryWhen.java:77) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.checkTerminate(FlowableFlatMap.java:566) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:374) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.innerError(FlowableFlatMap.java:605) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onError(FlowableFlatMap.java:668) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.error(FlowableCreate.java:288) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.tryOnError(FlowableCreate.java:277) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.onError(FlowableCreate.java:270) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual(FlowableCreate.java:75) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.Flowable.subscribe(Flowable.java:14291) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.Flowable.subscribe(Flowable.java:14237) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.onNext(FlowableFlatMap.java:163) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableOnBackpressureDrop$BackpressureDropSubscriber.onNext(FlowableOnBackpressureDrop.java:84) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableBuffer$PublisherBufferExactSubscriber.onNext(FlowableBuffer.java:126) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.operators.flowable.FlowableInterval$IntervalSubscriber.run(FlowableInterval.java:93) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at io.reactivex.internal.schedulers.ScheduledDirectPeriodicTask.run(ScheduledDirectPeriodicTask.java:38) [208:org.openhab.binding.meterreader:2.3.0.201804202130]
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [?:?]
at java.util.concurrent.FutureTask.runAndReset(Unknown Source) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(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) [?:?]
Caused by: java.io.IOException: wrong crc
at org.openmuc.jsml.transport.MessageExtractor.waitForStopSequence(MessageExtractor.java:113) ~[?:?]
at org.openmuc.jsml.transport.MessageExtractor.getSmlMessage(MessageExtractor.java:42) ~[?:?]
at org.openmuc.jsml.transport.Transport.getSMLFile(Transport.java:101) ~[?:?]
at org.openhab.binding.meterreader.internal.sml.SmlSerialConnector.readNext(SmlSerialConnector.java:73) ~[?:?]
at org.openhab.binding.meterreader.internal.sml.SmlSerialConnector.readNext(SmlSerialConnector.java:1) ~[?:?]
at org.openhab.binding.meterreader.connectors.ConnectorBase.emitValues(ConnectorBase.java:121) ~[?:?]
at org.openhab.binding.meterreader.connectors.ConnectorBase.lambda$2(ConnectorBase.java:98) ~[?:?]
at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual(FlowableCreate.java:72) ~[?:?]
... 14 more
I would really appreciate if you can help me to fix this issue.
@Payback:
First issue seems rather a OS or driver problem. Can you try to update your drivers?
Second issue was also reported by someone else. CRC error can occur time by time. Iâm not sure why itâs not recovering in next retry. I simply now disabled the retry handling and reopen the port as soon as something happens. This will recover immediately. It should not have eaten your resources though.
@msteigenberger first thanks for your continous support of the meterreader binding
While everything worked fine some time ago on an older OH version, I get an error on a newly test set up raspberry pi 3 with current OH 2.4 (testing build). The error is the same on my productive system.
2018-10-20 20:45:41.086 [me.event.ThingUpdatedEvent] - Thing 'meterreader:meter:0e7809a3' has been updated.
2018-10-20 20:45:41.127 [hingStatusInfoChangedEvent] - 'meterreader:meter:0e7809a3' changed from UNINITIALIZED (HANDLER_INITIALIZING_ERROR): org.eclipse.smarthome.core.thing.xml.internal.XmlChannelTypeProvider cannot be cast to org.openhab.binding.meterreader.internal.SmartMeterChannelTypeProvider to INITIALIZING
2018-10-20 20:45:41.165 [hingStatusInfoChangedEvent] - 'meterreader:meter:0e7809a3' changed from INITIALIZING to UNKNOWN (HANDLER_CONFIGURATION_PENDING): Waiting for messages from device
==> /var/log/openhab2/openhab.log <==
2018-10-20 20:45:41.174 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.meterreader.internal.MeterReaderHandler@3fd114': org.eclipse.smarthome.core.thing.xml.internal.XmlChannelTypeProvider cannot be cast to org.openhab.binding.meterreader.internal.SmartMeterChannelTypeProvider
java.lang.ClassCastException: org.eclipse.smarthome.core.thing.xml.internal.XmlChannelTypeProvider cannot be cast to org.openhab.binding.meterreader.internal.SmartMeterChannelTypeProvider
at org.openhab.binding.meterreader.internal.MeterReaderHandler.initialize(MeterReaderHandler.java:120) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.oh240M4]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.oh240M4]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
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) [?:?]
The reader is a IR Reader from volkszÀhler
In PaperUI the thing serial port config is /dev/ttyUSB0
hope this is correct.
Checked before `dmesg | grep tty and it gave [21992.531214] usb 1-1.1.2: cp210x converter now attached to ttyUSB0
@maxico: Yes, I already noticed this issue with the latest version (can occour by chance, was not occuring in development enviroment). I fixed it, but test is still pending. I will update it this weekend I hope.
@All: Please note: The binding has changed and is not compatible anymore in following points:
Binding name/id changed from âmeterreaderâ to âsmartmeterâ
Channel name/id changed: Char : and * is now mapped to _ instead of #
Old: 1-0#1-8-1 New: 1-0_1-8-1
No more NumberChannel or StringChannel ChannelTypes anymore. Instead each OBIS has its own ChannelType. Please see Readme.md for an example of how properties of Channels can now be modified in the .things file.
Removed conversionRatio from Channel Configuration. The unit which is provided by the meter is now taken fully into account when creating the Channel(-Type). Conversion to the desired unit (e.g. Wh to kWh) can now happen in the .items configuration by simply providing the desired unit there.
sorry for the late answer, don`t use openhab for a while.
Now i`ve reinstalled my raspberry / openhab installation and also the sml binding.
I use the /dev/ttyUSB0/ in my vzlogger.conf and get readings/values in the vzlogger.log.
But on PaperUI side with fresh SML Binding install from https://marketplace.eclipse.org/content/meterreader-binding i got errors, it don`t work for me anymore.
It doesnt stop my Zwave Controller (Razberry2) like in my first install, but Smart Meter dont start working and said âUNINITIALIZED - HANDLER_INITIALIZING_ERROR org.eclipse.smarthome.io.transport.serial.SerialPort.setFlowControlMode(I)Vâ or
âStatus: OFFLINE - COMMUNICATION_ERROR Serial port /dev/ttyUSB0 is already in use.â
@Hoecki: Is this the complete log? Exactly after the last line there should be a logging output that changes the state to ONLINE.
If this is not happening from what I analysed, it can only happen if there is no ChannelType found for the OBIS code. But the ChannelType should be generated beforehand from the value you received from the Meter. Iâm not sure why this is not working. Iâve added some debug information.
Can you please update the binding and attach the logs again?
Do you have a .things configuration?
@msteigenberger: Thanks for looking into it.
Yes it is the complete log. I tried it a again with the version 2.4.0.201810311653 of the binding. Same result:
2018-11-01 09:10:10.752 [DEBUG] [martmeter.internal.SmartMeterHandler] - Initializing Smartmeter handler.
2018-11-01 09:10:10.759 [DEBUG] [martmeter.internal.SmartMeterHandler] - config port = /dev/ttyUSB0
2018-11-01 09:10:10.779 [DEBUG] [artmeter.internal.sml.SmlMeterReader] - Created SmlDevice instance smartmeter:meter:4eeb97f3 with serial connector on port /dev/ttyUSB0
2018-11-01 09:10:11.185 [INFO ] [ding.smartmeter.internal.MeterDevice] - Opening connection to smartmeter:meter:4eeb97f3
2018-11-01 09:10:12.356 [TRACE] [artmeter.internal.sml.SmlMeterReader] - Read out following SML file:
2018-11-01 09:10:12.368 [TRACE] [artmeter.internal.sml.SmlMeterReader] - Got OpenResponse
2018-11-01 09:10:12.376 [TRACE] [artmeter.internal.sml.SmlMeterReader] - SML_PublicOpenRes{
codepage: not set
clientId: not set
reqFileId: 00 14 0B A4 42 EC
serverId: 08 05 34 D1 2D 4C A2 EE
refTime: Unknown tag: 0 value: unknown
smlVersion: 0
}
2018-11-01 09:10:12.380 [TRACE] [artmeter.internal.sml.SmlMeterReader] - Got GetListResponse
2018-11-01 09:10:12.413 [WARN ] [org.openmuc.jsml.EObis ] - Unknown OBIS Code: 01 00 00 00 09 FF
2018-11-01 09:10:12.418 [WARN ] [org.openmuc.jsml.EObis ] - Unknown OBIS Code: 01 00 01 08 00 FF
2018-11-01 09:10:12.423 [WARN ] [org.openmuc.jsml.EObis ] - Unknown OBIS Code: 01 00 01 08 02 FF
2018-11-01 09:10:12.427 [WARN ] [org.openmuc.jsml.EObis ] - Unknown OBIS Code: 01 00 10 07 00 FF
2018-11-01 09:10:12.435 [TRACE] [artmeter.internal.sml.SmlMeterReader] - SML_GetListRes{
serverId: 08 05 34 D1 2D 4C A2 EE
clientId: not set
listName: 01 00 62 0A FF FF
actSensorTime: SECINDEX value: 195343520
valList: SML_List{
entry: SML_ListEntry{
objName: DEVICE_INFO_MANUFACTOR 81 81 C7 82 03 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: EMPTY
scaler: 0
value: 45 4D 48
valueSignature: not set
}
entry: SML_ListEntry{
objName: UNKNOWN 01 00 00 00 09 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: EMPTY
scaler: 0
value: 08 05 34 D1 2D 4C A2 EE
valueSignature: not set
}
entry: SML_ListEntry{
objName: UNKNOWN 01 00 01 08 00 FF
status: SML_Status{
choice: 386
}
valTime: Unknown tag: 0 value: unknown
unit: WATT_HOUR
scaler: -1
value: 241364328
valueSignature: not set
}
entry: SML_ListEntry{
objName: LOADPROFILE_E_IMPORT_TARIFF_1 01 00 01 08 01 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: WATT_HOUR
scaler: -1
value: 241364328
valueSignature: not set
}
entry: SML_ListEntry{
objName: UNKNOWN 01 00 01 08 02 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: WATT_HOUR
scaler: -1
value: 0
valueSignature: not set
}
entry: SML_ListEntry{
objName: UNKNOWN 01 00 10 07 00 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: WATT
scaler: -1
value: 4717
valueSignature: not set
}
entry: SML_ListEntry{
objName: DEVICE_INFO_PUBLIC_KEY 81 81 C7 82 05 FF
status: SML_Status{
choice: not set
}
valTime: SECINDEX value: 195343520
unit: EMPTY
scaler: 0
value: F4 A6 88 D4 8D 8C EF 52 E8 AC 60 0C 0B 6A D2 BF 75 19 F0 92 7B 5E F3 88 A7 74 FB E1 1E 90 3C 00 FA 10 24 FC 48 82 09 8F D5 37 F9 1D E0 9C 60 2D
valueSignature: not set
}
}
listSignature: not set
actGatewayTime: Unknown tag: 0 value: unknown
}
2018-11-01 09:10:12.438 [TRACE] [artmeter.internal.sml.SmlMeterReader] - Got CloseResponse
2018-11-01 09:10:12.440 [TRACE] [artmeter.internal.sml.SmlMeterReader] - SML_PublicCloseRes{
globalSignature: not set
}
2018-11-01 09:10:12.454 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=129-129:199.130.3, value=45 4D 48, unit=null]
2018-11-01 09:10:12.458 [DEBUG] [artmeter.internal.MeterValueListener] - Creating ChannelType for OBIS 129-129:199.130.3
I didnât use a things file. But I tried it today with one:
smartmeter:meter:BinderPower [port="/dev/ttyUSB0", refresh=5] {
Channels:
Type 1-0_1-8-0 : 1-0_1-8-0
}
The result was the following trace:
2018-11-01 09:35:15.423 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'smartmeter.things'
2018-11-01 09:35:15.475 [ERROR] [.thing.internal.GenericThingProvider] - Channel type smartmeter:1-0_1-8-0 could not be resolved.
2018-11-01 09:35:15.496 [DEBUG] [martmeter.internal.SmartMeterHandler] - Initializing Smartmeter handler.
2018-11-01 09:35:15.502 [DEBUG] [martmeter.internal.SmartMeterHandler] - config port = /dev/ttyUSB0
2018-11-01 09:35:15.504 [DEBUG] [artmeter.internal.sml.SmlMeterReader] - Created SmlDevice instance smartmeter:meter:BinderPower with serial connector on port /dev/ttyUSB0
2018-11-01 09:35:15.508 [INFO ] [ding.smartmeter.internal.MeterDevice] - Opening connection to smartmeter:meter:BinderPower
2018-11-01 09:35:17.694 [TRACE] [artmeter.internal.sml.SmlMeterReader] - Read out following SML file:
2018-11-01 09:35:17.699 [TRACE] [artmeter.internal.sml.SmlMeterReader] - Got OpenResponse
2018-11-01 09:35:17.708 [TRACE] [artmeter.internal.sml.SmlMeterReader] - SML_PublicOpenRes{
codepage: not set
clientId: not set
reqFileId: 00 14 0B A4 49 E2
serverId: 08 05 34 D1 2D 4C A2 EE
refTime: Unknown tag: 0 value: unknown
smlVersion: 0
}
2018-11-01 09:35:17.713 [TRACE] [artmeter.internal.sml.SmlMeterReader] - Got GetListResponse
2018-11-01 09:35:17.726 [WARN ] [org.openmuc.jsml.EObis ] - Unknown OBIS Code: 01 00 00 00 09 FF
2018-11-01 09:35:17.735 [WARN ] [org.openmuc.jsml.EObis ] - Unknown OBIS Code: 01 00 01 08 00 FF
2018-11-01 09:35:17.746 [WARN ] [org.openmuc.jsml.EObis ] - Unknown OBIS Code: 01 00 01 08 02 FF
2018-11-01 09:35:17.755 [WARN ] [org.openmuc.jsml.EObis ] - Unknown OBIS Code: 01 00 10 07 00 FF
2018-11-01 09:35:17.773 [TRACE] [artmeter.internal.sml.SmlMeterReader] - SML_GetListRes{
serverId: 08 05 34 D1 2D 4C A2 EE
clientId: not set
listName: 01 00 62 0A FF FF
actSensorTime: SECINDEX value: 195345026
valList: SML_List{
entry: SML_ListEntry{
objName: DEVICE_INFO_MANUFACTOR 81 81 C7 82 03 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: EMPTY
scaler: 0
value: 45 4D 48
valueSignature: not set
}
entry: SML_ListEntry{
objName: UNKNOWN 01 00 00 00 09 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: EMPTY
scaler: 0
value: 08 05 34 D1 2D 4C A2 EE
valueSignature: not set
}
entry: SML_ListEntry{
objName: UNKNOWN 01 00 01 08 00 FF
status: SML_Status{
choice: 386
}
valTime: Unknown tag: 0 value: unknown
unit: WATT_HOUR
scaler: -1
value: 241366112
valueSignature: not set
}
entry: SML_ListEntry{
objName: LOADPROFILE_E_IMPORT_TARIFF_1 01 00 01 08 01 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: WATT_HOUR
scaler: -1
value: 241366112
valueSignature: not set
}
entry: SML_ListEntry{
objName: UNKNOWN 01 00 01 08 02 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: WATT_HOUR
scaler: -1
value: 0
valueSignature: not set
}
entry: SML_ListEntry{
objName: UNKNOWN 01 00 10 07 00 FF
status: SML_Status{
choice: not set
}
valTime: Unknown tag: 0 value: unknown
unit: WATT
scaler: -1
value: 3932
valueSignature: not set
}
entry: SML_ListEntry{
objName: DEVICE_INFO_PUBLIC_KEY 81 81 C7 82 05 FF
status: SML_Status{
choice: not set
}
valTime: SECINDEX value: 195345026
unit: EMPTY
scaler: 0
value: F4 A6 88 D4 8D 8C EF 52 E8 AC 60 0C 0B 6A D2 BF 75 19 F0 92 7B 5E F3 88 A7 74 FB E1 1E 90 3C 00 FA 10 24 FC 48 82 09 8F D5 37 F9 1D E0 9C 60 2D
valueSignature: not set
}
}
listSignature: not set
actGatewayTime: Unknown tag: 0 value: unknown
}
2018-11-01 09:35:17.778 [TRACE] [artmeter.internal.sml.SmlMeterReader] - Got CloseResponse
2018-11-01 09:35:17.782 [TRACE] [artmeter.internal.sml.SmlMeterReader] - SML_PublicCloseRes{
globalSignature: not set
}
2018-11-01 09:35:17.790 [DEBUG] [ding.smartmeter.internal.MeterDevice] - Value changed: MeterValue [obis=129-129:199.130.3, value=45 4D 48, unit=null]
2018-11-01 09:35:17.794 [DEBUG] [artmeter.internal.MeterValueListener] - Creating ChannelType for OBIS 129-129:199.130.3
Yes, OH is still running after that. I still can switch my power outlets. There are no more logs in the openhab.log, but still logs in the event.log (not from your binding) . Any additional information I can provide?
One thing I noticed is:
Iâam using the USB-Reader from Volkszaehler (Udo) with an eHZ-IW8E2A5L0EK2P. Which ist very similiar to your test hardware configuration. Iâam running OH installed from the repository on raspbian.
Can you please execute jstack -F <PID> (where PID is the Process ID of the OH process/java) from your system and attach the output here?
Which JDK are you using (java -v)?
jstack -F is also not working.
My java only knows jstack -l. But it doesnât seem to return anything useful :
holger@OpenHab2:/var/log/openhab2 $ ps -u openhab
PID TTY TIME CMD
14760 ? 03:04:33 java
holger@OpenHab2:/var/log/openhab2 $ sudo jstack -l 14760
14760: Unable to open socket file: target process not responding or HotSpot VM not loaded
holger@OpenHab2:/var/log/openhab2 $
holger@OpenHab2:/usr/bin $ ls -l /etc/alternatives/java
lrwxrwxrwx 1 root root 53 Nov 1 16:40 /etc/alternatives/java -> /usr/lib/jvm/jdk-8-oracle-arm32-vfp-hflt/jre/bin/java
The status in the PaperUI ist still: Status: UNKNOWN - HANDLER_CONFIGURATION_PENDING Waiting for messages from device
holger@OpenHab2:~ $ java -version
java version "1.8.0_65"
Java(TM) SE Runtime Environment (build 1.8.0_65-b17)
Java HotSpot(TM) Client VM (build 25.65-b01, mixed mode)
holger@OpenHab2:~ $ sudo jstack -F 23519
Attaching to process ID 23519, please wait...
Debugger attached successfully.
Client compiler detected.
JVM version is 25.65-b01
Deadlock Detection:
java.lang.RuntimeException: Unable to deduce type of thread from address 0x00c7e400 (expected type JavaThread, CompilerThread, ServiceThread, JvmtiAgentThread, or SurrogateLockerThread)
at sun.jvm.hotspot.runtime.Threads.createJavaThreadWrapper(Threads.java:166)
at sun.jvm.hotspot.runtime.Threads.first(Threads.java:150)
at sun.jvm.hotspot.runtime.DeadlockDetector.createThreadTable(DeadlockDetector.java:149)
at sun.jvm.hotspot.runtime.DeadlockDetector.print(DeadlockDetector.java:56)
at sun.jvm.hotspot.runtime.DeadlockDetector.print(DeadlockDetector.java:39)
at sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:62)
at sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:45)
at sun.jvm.hotspot.tools.JStack.run(JStack.java:66)
at sun.jvm.hotspot.tools.Tool.startInternal(Tool.java:260)
at sun.jvm.hotspot.tools.Tool.start(Tool.java:223)
at sun.jvm.hotspot.tools.Tool.execute(Tool.java:118)
at sun.jvm.hotspot.tools.JStack.main(JStack.java:92)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at sun.tools.jstack.JStack.runJStackTool(JStack.java:140)
at sun.tools.jstack.JStack.main(JStack.java:106)
Caused by: sun.jvm.hotspot.types.WrongTypeException: No suitable match for type of address 0x00c7e400
at sun.jvm.hotspot.runtime.InstanceConstructor.newWrongTypeException(InstanceConstructor.java:62)
at sun.jvm.hotspot.runtime.VirtualConstructor.instantiateWrapperFor(VirtualConstructor.java:80)
at sun.jvm.hotspot.runtime.Threads.createJavaThreadWrapper(Threads.java:162)
... 17 more
Can't print deadlocks:Unable to deduce type of thread from address 0x00c7e400 (expected type JavaThread, CompilerThread, ServiceThread, JvmtiAgentThread, or SurrogateLockerThread)
Exception in thread "main" java.lang.reflect.InvocationTargetException
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at sun.tools.jstack.JStack.runJStackTool(JStack.java:140)
at sun.tools.jstack.JStack.main(JStack.java:106)
Caused by: java.lang.RuntimeException: Unable to deduce type of thread from address 0x00c7e400 (expected type JavaThread, CompilerThread, ServiceThread, JvmtiAgentThread, or SurrogateLockerThread)
at sun.jvm.hotspot.runtime.Threads.createJavaThreadWrapper(Threads.java:166)
at sun.jvm.hotspot.runtime.Threads.first(Threads.java:150)
at sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:75)
at sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:45)
at sun.jvm.hotspot.tools.JStack.run(JStack.java:66)
at sun.jvm.hotspot.tools.Tool.startInternal(Tool.java:260)
at sun.jvm.hotspot.tools.Tool.start(Tool.java:223)
at sun.jvm.hotspot.tools.Tool.execute(Tool.java:118)
at sun.jvm.hotspot.tools.JStack.main(JStack.java:92)
... 6 more
Caused by: sun.jvm.hotspot.types.WrongTypeException: No suitable match for type of address 0x00c7e400
at sun.jvm.hotspot.runtime.InstanceConstructor.newWrongTypeException(InstanceConstructor.java:62)
at sun.jvm.hotspot.runtime.VirtualConstructor.instantiateWrapperFor(VirtualConstructor.java:80)
at sun.jvm.hotspot.runtime.Threads.createJavaThreadWrapper(Threads.java:162)
... 14 more
