Plugwise Binding Failure

[ianlin...@gmail.com]

Hi,

I've spent a lot of time trying to diagnose a problem with the Plugwise binding. It seems that after a period of time (varies between a few minutes and a few hours) it will stop sending and receiving data. I've had the debugger attached and so far I can tell that:

1. The serial event in stick.java isn't firing

2. The Quartz jobs aren't firing either

I can only assume that something has died and cause the quartz jobs to die also. Although they still exist in memory as I can see them when I look at the the Quartz thread,  they just aren't firing anymore. 

I've tried two different hardware platforms and both on Ubuntu and Windows, 32bit and 64bit and it results in the same strange behavior. The only constants are:

a) The stick (which works fine with Plugwise)

b) The config (below)

c) NRJavaSerial Library

d) Openhab and it's config

Can anyone help? I've attached the config for the plugwise items below:

Number  HallPower "Hall Switch Power [%d]"  <plugwise>  { plugwise="[000D6F0000D364C8:power:3]"}

Switch  HallSwitch  "Hall"  <plugwise> { plugwise="[ON:000D6F0000D364C8:state:15], [OFF:000D6F0000D364C8:state:15]"}

Number  LoungePower "Lounge Switch Power [%d]"  <plugwise>  { plugwise="[000D6F000076A444:power:3]"}

Switch  LoungeSwitch "Lounge"  <plugwise> { plugwise="[ON:000D6F000076A444:state:15], [OFF:000D6F000076A444:state:15]"}

Number  FrontDoorPower "Front Door Switch Power [%d]"  <plugwise>  { plugwise="[000D6F0000D33CC5:power:3]"}

Switch  FrontDoorSwitch "Front Door"  <plugwise> { plugwise="[ON:000D6F0000D33CC5:state:15], [OFF:000D6F0000D33CC5:state:15]"}

Thanks,

Ian

[Karel Goderis]

Hi Ian

Thank you for that feedback. Although I have written the Plugwise binding, your setup is simply more advanced than mine, just because mine is still very much virtual - I am renovating a house, and that is far from done. So, that being said, I can only guess at what might be going on unfortunately.

First of all, I developed the binding in the RxTx serial lib era, so, I can not comment if the NRSerial lib is to blame. But, when you tell me that both problem 1. and 2. are occurring at the same time, I think there might be a problem with the Java VM. Initially, what was effectively a problem with the binding, was the fact that the Quartz lib failed because of firing events too rapidly. You see, there is no facility to continuously trigger events in Quartz, you can only set the firing interval small enough. If I remember well, this is set to be at 50ms, which sounded to me be "reasonable". But it failed sometimes. That problem however was solved by moving to Java 7.

When I developed the Plugwise binding with RxTx serial lib, well, that lib had nothing to do with Quartz, and it had its own threading logic to trigger events when data is arriving on the serial port. If you say that both problems occur at the same time, and assuming that NRJavaSerial is not Quartz-based (I have no clue about that), I can only assume that something at the Virtual Machine level is breaking down. I presume that the problem does not prevail when you "step" manually through the code?

Unfortunately I am bit short on time to test out the binding based on the new serial lib, and I need to study my own code as well (been a bit of time since I have written the binding), plunge back into a java-code-writing-mindset etc. I more than happy to look into the problem when I will get to the software bit of my home project.....

Regards

Karel

--
You received this message because you are subscribed to the Google Groups "openhab" group.
To unsubscribe from this group and stop receiving emails from it, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab?hl=en.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

[Kai Kreuzer]

Karel,

> assuming that NRJavaSerial is not Quartz-based (I have no clue about that)

Just to clarify: NRJavaSerial is an "OSGi packaging" of the RXTX libraries, i.e. for serial communication. This should behave completely identical to the previous RXTX in the openHAB lib folder. As RXTX has nothing to do with Quartz (which is a scheduler), the same holds true for NRJavaSerial - there is no connection with Quartz.

Btw, using Quartz to schedule jobs every 50ms might indeed be not a good idea after all. If you require such frequent actions, you would probably be better off with your own thread (and use sleep(50) inbetween). I must have overlooked this when reviewing your code, so sorry that I only come up now with this comment!

Best regards,
Kai

[ianlin...@gmail.com]

Karel and Kai,

Thanks both for the quick reply. I'll have a go at changing the codes to use a thread instead of quartz and report back. I appreciate the quick response and the thoughts, it has given me some inspiration as I was starting to run out!

Ian

[Karel Goderis]

Ian

Whilst true for the Quartz polling bit, it does not explain why the RxTx bit is blocking.....

K

[Karel Goderis]

There is a solution to in the sense that you (I do not recall the exact Quartz class) can watch the execution of a quartz job, and when it is finished, schedule it again. See the refactored TCP binding on how that can be done.

I was only suggesting that this could be the source of the problem, but it never showed up in my testing however.

It needs to be investigated a bit further I guess before we make any drastic changes


K

[ianlin...@gmail.com]

Just done some more testing and I don't think quartz is the problem as I've converted two of the jobs to threads and it just died in the same way. Time to spend more time with the debugger. Do either of you know of an alternative serial driver and I'll see if I can integrate that.

Thanks,

Ian

[Kai Kreuzer]

Hi Ian,

> Do either of you know of an alternative serial driver and I'll see if I can integrate that.

Not really - RXTX is the de-facto open source standard for Java serial communication.

Regards,
Kai

[Karel Goderis]

Ian

Do you have any particular Java / Virtual Machine setup which might be the cause?

K

[ianlin...@gmail.com]

I don't think it's Java that's the cause it's the 32bit 1.7 and I'm running on Win 8 (but so does plugwise an it runs ok), plus I had the same issue on Ubunu 32 bit.

[ianlin...@gmail.com]

Ok, So I might have found what the problem is... seems the "sentQueue" is filling up and then blocking, and then think the "RecieveQueue" is then filling up because the blocked "sentQueue" is stopping processing of further messages. I just need to find out now if it's a leak... i.e. there are some messages that should be removed, or because of my set up I get a lot of lost messages. For the moment, I'm rebuilding with a larger buffer on send and receive as a quick fix. I know I have modules that sometimes drop out the network or, get physically switched off (I have a 2 year old with itchy fingers! :-))

Ian

[Max Stephan]

Hi,

was that issue finally fixed ? I currently think of giving openhab a try as well with my plugwise devices and want to make sure any faults that might happen are just my config ;)

thx,

Max

[Gert Konemann]

Hello all,

I did some tests with the plugwise binding and found that:

1. The log shows an errormessage for each circle and circle+ with its macaddress at startup of openHAB.

2. I can switch the circles. Each switch action give an errormessage from that circle.

3. I cannot see the powerconsumption of a circle.

My circles have firmware versions dated 20110513 (version 2.36) and 20110627.

A sample from the logfile:

10:46:16.998 ERROR o.o.b.plugwise.internal.Stick[:454] - Plugwise protocol message error: # APSRequestNodeInfo: Source MAC: 000D6F0000598CB3

# APSRequestNodeInfo: Destination MAC:

10:46:17.029 ERROR o.o.b.plugwise.internal.Stick[:451] - Plugwise protocol header error: 000D in message 000D6F0000729773

10:46:17.295 ERROR o.o.b.plugwise.internal.Stick[:454] - Plugwise protocol message error: # APSRequestNodeInfo: Source MAC: 000D6F0000598CB3

# APSRequestNodeInfo: Destination MAC:

10:46:17.310 ERROR o.o.b.plugwise.internal.Stick[:451] - Plugwise protocol header error: 000D in message 000D6F000011EFA5

10:46:17.497 ERROR o.o.b.plugwise.internal.Stick[:454] - Plugwise protocol message error: # APSRequestNodeInfo: Source MAC: 000D6F0000598CB3

# APSRequestNodeInfo: Destination MAC:

10:47:32.313 INFO  runtime.busevents[:42] - Notebooki3_s received command OFF

10:47:32.370 ERROR o.o.b.plugwise.internal.Stick[:454] - Plugwise protocol message error: # APSRequestNodeInfo: Source MAC: 000D6F0000598CB3

# APSRequestNodeInfo: Destination MAC:

10:47:32.391 ERROR o.o.b.plugwise.internal.Stick[:451] - Plugwise protocol header error: 000D in message 000D6F0000236C12

10:47:32.530 INFO  runtime.busevents[:46] - Notebooki3_s state updated to OFF

10:47:33.574 INFO  runtime.busevents[:42] - Notebooki3_s received command ON

10:47:33.640 ERROR o.o.b.plugwise.internal.Stick[:454] - Plugwise protocol message error: # APSRequestNodeInfo: Source MAC: 000D6F0000598CB3

# APSRequestNodeInfo: Destination MAC:

10:47:33.641 ERROR o.o.b.plugwise.internal.Stick[:451] - Plugwise protocol header error: 000D in message 000D6F0000236C12

10:47:33.779 INFO  runtime.busevents[:46] - Notebooki3_s state updated to ON

Can someone help me ?

Gert Konemann

_________________________________________________________________________________________________________

Op woensdag 20 februari 2013 22:08:21 UTC+1 schreef ianlin...@gmail.com:

[Karel Goderis]

Hi Gert

The binding is a reverse-engineering effort, so for each part of the protocol that it does not (yet) understand, it spits out the kind of error message as you see in your logs. Most of the time you should not worry about these

With respect to the firmware version I can not currently tell if you are behind of in front of me in terms of version numbers, I need to check at home. 

Did you define the MAC addresses in the openhab.cfg or directly in the .items binding config? can you share the relevant parts of those files, as well as the log file when starting up  OH?

Regards

Karel

--
You received this message because you are subscribed to the Google Groups "openhab" group.
To unsubscribe from this group and stop receiving emails from it, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.

Visit this group at http://groups.google.com/group/openhab.

[Gert Konemann]

Hi Ben,

This is what i defined in openhab.cfg for plugwise:

############################## Plugwise Binding #######################################

#

# "stick" is reserved plug wise id

plugwise:stick.port=COM3

# "circleplus" is reserved plug wise id

plugwise:circleplus.mac=000D6F0000729773

# circles can be defined here, but the preferred place is in the items file.

#plugwise:<plugwise-id-1>.mac=

and in the items file:

/* Plugwise circles */

/*

Number Internetradio "Internetradio [%.2f W]" <socket> (Huiskamer, Energie) {plugwise="[000D6F0000736898:power:20]"}

Number Lampje_stereohoek "Lampje_Stereohoek [%.2f W]" <socket> (Huiskamer, Energie) {plugwise="[000D6F000023722B:power:20]"}

Number Notebooki3 "Notebooki3 [%.2f W]" <socket> (Huiskamer, Energie) {plugwise="[000D6F0000236C12:power:20]"}

Number TVhoek "TVhoek [%.2f W]" <socket> (Huiskamer, Energie) {plugwise="[000D6F000011E9D8:power:20]"}

Number Acer_monitor "Acer_monitor [%.2f W]" <socket> (Kantoor, Energie) {plugwise="[000D6F00029C24EF:power:20]"}

Number Bureau "Bureau [%.2f W]" <socket> (Kantoor, Energie) {plugwise="[000D6F0000729773:power:20]"}

Number Compex_5p_switch "Compex_5p_switch [%.2f W]" <socket> (Kantoor, Energie) {plugwise="[000D6F00029C344E:power:20]"}

Number EEE_Box     "EEE-Box [%.2f W]" <socket> (Kantoor, Energie) {plugwise="[000D6F00002371E3:power:20]"}

Number Scott_monitor "Scott_monitor [%.2f W]" <socket> (Kantoor, Energie) {plugwise="[000D6F00029C33EF:power:20]"}

Number Stereo_zolder "Stereo_zolder [%.2f W]" <socket> (Kantoor, Energie) {plugwise="[000D6F00035631DD:power:20]"}

Number Koelkast "Koelkast [%.2f W]" <socket> (Keuken, Energie) {plugwise="[000D6F00004BA1D9:power:20]"}

Number Magnetronoven    "Magnetron [%.2f W]" <socket> (Keuken, Energie) {plugwise="[000D6F00005529C4:power:20]"}

Number Nespresso "Nespresso [%.2f W]" <socket> (Keuken, Energie) {plugwise="[000D6F0000736433:power:20]"}

Number Vaatwasser "Vaatwasser [%.2f W]" <socket> (Keuken, Energie) {plugwise="[000D6F0000729F34:power:20]"}

Number Vriezer "Vriezer [%.2f W]" <socket> (Keuken, Energie) {plugwise="[000D6F0000553560:power:20]"}

Number Lamp_carport "Lamp_carport [%.2f W]" <socket> (Schuur, Energie) {plugwise="[000D6F0000236C70:power:20]"}

Number Koelcombi "Koelcombi [%.2f W]" <socket> (Schuur, Energie) {plugwise="[000D6F000013918D:power:20]"}

Number Bedlampen_radio "Bedlampen_radio [%.2f W]" <socket> (Slaapkamer, Energie) {plugwise="[000D6F0000737661:power:20]"}

Number HP_switch "HP_switch [%.2f W]" <socket> (Werkkast, Energie) {plugwise="[000D6F0000736B78:power:20]"}

Number Centrale_Ventilator "Centrale_Ventilator [%.2f W]" <socket> (Zolder, Energie) {plugwise="[000D6F000011EFA5:power:20]"}

Number CV_ketel "CV_ketel [%.2f W]" <socket> (Zolder, Energie) {plugwise="[000D6F00001156F2:power:20]"}

*/ 

/* Plugwise schakelaars */

Switch Notebooki3_s "Notebooki3_s" <socket> (Huiskamer) {plugwise="[ON:000D6F0000236C12:state:15], [OFF:000D6F0000236C12:state:15]"}

Switch Nespresso_s "Nespresso_s" <socket> (Keuken) {plugwise="[ON:000D6F0000736433:state:15], [OFF:000D6F0000736433:state:15]"}

Excerpts of the logfile are in my previous post. There are the errormessages and also succesful logging of switching actions.

I expect that the firmware version of the circles is OK, because it is the latest version and last changed in 2011.

Gert

Op dinsdag 15 oktober 2013 15:05:13 UTC+2 schreef karel....@me.com:

[Gert Konemann]

Sorry,

I meant Karel instead of Ben.

Gert

Op zaterdag 19 oktober 2013 21:42:35 UTC+2 schreef Gert Konemann:

[Max Stephan]

Hi,

I am pretty confident meanwhile this issue is related to load either in openhab (unlikely) or with the Plugwise stick/network (likely).

People who only have a few Circles seem to have no issue, while those with 10 (eg me) or more (eg Gert) have those issues. As I understand the binding when eg configured for 15 sec polling interval requests updates from ALL circles at the same time and then waits for asynchronous response of ALL circles. Is it possible to change this just for testing into a "one by one" scenario where the next circle is only polled when the previous either replied or timed out eg three times ?

As far as I understand from some of the unleashed articles around the Plugwise network is relatively unstable in the sense that some requests seem to get lost or overseen... Asynchronous polling seems to increase that. Source itself is polling one by one as well as I understand.

Max

[Karel Goderis]

On 24 Oct 2013, at 08:56, Max Stephan <max.s...@gmx.de> wrote:

> Hi,
>
> I am pretty confident meanwhile this issue is related to load either in openhab (unlikely) or with the Plugwise stick/network (likely).
>
> People who only have a few Circles seem to have no issue, while those with 10 (eg me) or more (eg Gert) have those issues. As I understand the binding when eg configured for 15 sec polling interval requests updates from ALL circles at the same time and then waits for asynchronous response of ALL circles. Is it possible to change this just for testing into a "one by one" scenario where the next circle is only polled when the previous either replied or timed out eg three times ?
>
> As far as I understand from some of the unleashed articles around the Plugwise network is relatively unstable in the sense that some requests seem to get lost or overseen... Asynchronous polling seems to increase that. Source itself is polling one by one as well as I understand.
>
> Max
>

Obviously, I fall in the category of people with only a few Circles, and thus during initial development of the binding I never encountered the issue. I think you have a very good point with respect to managing the flow of poll requests.

The current approach is as follows: take a list of all variables that need to be polled for each device, figure out the kind of job that is required, set-up a repeating Quartz Job that is triggered each "interval" (as specified in the binding config in .items) and let that run forever.

I can imagine that when the binding is loaded, it will traverse the binding config very rapidly, and thus all the Quartz jobs, even if scheduled independent from each other, are scheduled very shortly after each other, resulting in "bursts" in the Quartz scheduler. There are a few solutions we could try:

1. Pace the scheduling of the Quartz Jobs in PlugwiseBinding.bindingChanged()
2. Put some re-entrant lock mechanism in the jobs defined in Stick (Stick.PowerBufferJob etc), combined with some timing mechanism to monitor the time between messages sent over the ZigBee network. (Locks are already use elsewhere)
3. Pace the SendJob that picks messages from a Queue . (Messages that are to be sent on the network are put in a Queue, and a Stick.SendJob job is polling the queue and sending off messages
4. Investigate a bit Quartz in detail if there is another mechanism to pace Jobs in the first place.

The easiest to experiment with, and to control through a configuration parameter in openhab.cfg, is obviously option 3. We could even add some code to check the sendQueue in order to remove "duplicate" poll messages in case they are generated too fast, and thus reduce the load on the network.

Karel

[Gert Konemann]

I tested with an items file with only plugwise items (attachment plugwise.items). If there are only measurement items in the file there are only errors the first minutes after te startup of openHAB. See attachment plugwise_measure_only. When I remove the // on the last two lines of the items file, the errors do not stop. See attachment plugwise_with_switches.txt. Trying to switch a circle sometimes does not work and stops the measurements (attachment plugwise_switching_stops_measurements.txt), another time the switch action is executed and measurements go on (attachment plugwise_switch_executed).

I hope this helps to find the problem. I use version 1.4.0 #515.

Gert

Op donderdag 24 oktober 2013 10:03:05 UTC+2 schreef karel....@me.com:

[Karel Goderis]

Gert

I think that the rate of messages sent over the ZigBee network has to be carefully managed (it could equally be a limitation of the Stick or Stick firmware), and thus need further investigation. What you experience is not normal behaviour for sure, but I think the nature of what you describe is due to the ZigBee network beging flooded, and not the code in the binding itself. That code itself is rather straight forward (I think ;-) ). You do have quite an extensive group of plugwise devices. Also, what it is a bit strange is that you measure negative (but small) power consumption on some devices.... Do you observe the same in the Plugwise Source? (I used Source to verify the source code of the binding, but I have never seen *negative* values)

Karel

ps. I am a bit short in time this week, I am moving places on Thursday. Any patching will be for next week...

--
You received this message because you are subscribed to the Google Groups "openhab" group.
To unsubscribe from this group and stop receiving emails from it, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab.
For more options, visit https://groups.google.com/groups/opt_out.

<plugwise_measure_only.txt><Plugwise.items><plugwise_with_switches.txt><plugwise_switching_stops_measurements.txt><plugwise_switch_executed.txt>

[Karel Goderis]

Gert

do you also experience the effects/problems described here https://code.google.com/p/openhab/issues/detail?id=496 ?

K

[Gert Konemann]

Yes, that also happens here.

Gert

Op maandag 28 oktober 2013 00:05:37 UTC+1 schreef karel....@me.com:

[Gert Konemann]

Karel,

In Source I have no problems. I use it for years. I think of replacing the binding by http acces to Source. Then I use a well documented api. That is also done in the Homeseer Addin for Plugwise. In that way all Plugwise devices are supported, but you need a 24h powered Windows machine. You can avoid that with a Plugwise Stretch. Its (html) api is also documented. I need a html solution for the plugwise Smile P1 anyhow. It has no ZigBee interface. The elegance of the binding is that Stick owners get platform independent too. Therefore I remain interested. 

Gert

Op maandag 28 oktober 2013 00:02:17 UTC+1 schreef karel....@me.com:

[Karel Goderis]

Ok

At the time I started the coding effort there was no such thing as a Stretch, but it is an interersting alternative path. My plugwise binding was/is up to now relatively small (acquired it before my current home build-out), so, "large scale" testing was not done up to now.

Obviously, the advantage of using a Stretch is that one does not need to reverse-engineer the protocol. I could use your help to get all the bugs out of the binding

K

[Gert Konemann]

Karel,

Now I have the alternative solution running. OpenHAB is very flexible. Especially with the http binding you can realise things in very short time. I have sort of documented what I did in the attached files. Now I can access all my devices with openHAB, it is time to learn about creating graphs and automation.

thanks for your help,

Gert

Op dinsdag 29 oktober 2013 07:52:35 UTC+1 schreef karel....@me.com:

[Karel Goderis]

Gert

Great! 5. in your list I hope to fix soon. I personally do not have/like Windows, so I am still biased towards a native Java openHAB integration.

I will continue to support the plugwise binding in the future, although I will not use it as I have decided to wire very socket in my house to KNX Actuators that can do power metering. (crazy, I know ;-) )

Karel

<Control Plugwise Source with the openHAB http binding.doc><plugwise_source_demo.items>

[Gert Konemann]

Laurens,

I do not know which version of my solution you tried. I think that you have the first version. A few days later i added a rule to set the initial state of the circles and it also solves this after unplugging and plugging in again a circle. In the attachment you find my sample configuration. Feel free to ask if you need more explanation.

Gert

2014-04-03 15:46 GMT+02:00 Laurens Lammens <laurens...@gmail.com>:

Gert,

i tried your xml solutions for plugwise http bindings and it works great, except for the switch.xml
it does not seem to give the initial status of the switches
here is an example of item

Switch     sBoiler            "Boiler"                                 <socket>     (Switches)     {http=">[ON:POST:http://admin:visions1!@192.168.1.12:8190/api/switch.xml?cmd=on&mac=000D6F000278B85F] >[OFF:POST:http://admin:visions1!@192.168.1.12:8190/api/switch.xml?cmd=off&mac=000D6F000278B85F]"}

is there any way to pass initial switch status (on/off)?

br,
Laurens

--
You received this message because you are subscribed to a topic in the Google Groups "openhab" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/openhab/DuwV7t7H4XA/unsubscribe.
To unsubscribe from this group and all its topics, send an email to openhab+u...@googlegroups.com.

To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab.

For more options, visit https://groups.google.com/d/optout.

[Gert Konemann]

I also had problems with the official binding. There is another Plugwise binding which controls the stick directly made by fireson. I tested it a few days and in my configuration it works well. I assume you can find it somewhere on this forum.

Gert