SmartAxiom / openhab

Automatically exported from code.google.com/p/openhab
0 stars 0 forks source link

Plugwise Binding. Silent Stop/Crash #199

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago
I'm running the Plugwise binding on Windows 8 x64 after an indeterminate amount 
of time the plugwise binding stops working. No action on switches etc... but 
also it stops producing the INFO messages. 

Here's the last few entries from the log (I've attached the full log file)

01:25:48.928 ERROR o.o.b.plugwise.internal.Stick[:454]- Plugwise protocol 
message error: # APSRequestNodeInfo: Source MAC: 000D6F0000C3D33A# 
APSRequestNodeInfo: Destination MAC:  
01:25:48.943 ERROR o.o.b.plugwise.internal.Stick[:451]- Plugwise protocol 
header error: 000D in message 000D6F0000769879
01:25:48.959 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:ACKNOWLEDGEMENT sequence:51203 payload:00C1
01:25:48.959 INFO  o.o.b.plugwise.internal.Stick[:665]- Sending Plugwise 
protocol data unit: attempts: 1 MAC:000D6F000076A0ED 
command:POWER_INFORMATION_REQUEST sequence:0 full HEX:0012000D6F000076A0ED0B74
01:25:49.006 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:DEVICE_INFORMATION_RESPONSE sequence:51202 
payload:000D6F00007698790D023E350004D3B000856539090048044DCCDAF301
01:25:49.021 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:ACKNOWLEDGEMENT sequence:51204 payload:00C1
01:25:49.021 INFO  o.o.b.plugwise.internal.Stick[:665]- Sending Plugwise 
protocol data unit: attempts: 1 MAC:000D6F000076A444 
command:DEVICE_INFORMATION_REQUEST sequence:0 full HEX:0023000D6F000076A44482DB
01:25:49.037 ERROR o.o.b.plugwise.internal.Stick[:454]- Plugwise protocol 
message error: # APSRequestNodeInfo: Source MAC: 000D6F0000C3D33A# 
APSRequestNodeInfo: Destination MAC:  
01:25:49.053 ERROR o.o.b.plugwise.internal.Stick[:451]- Plugwise protocol 
header error: 000D in message 000D6F000076A0ED
01:25:49.068 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:POWER_INFORMATION_RESPONSE sequence:51203 
payload:000D6F00007698790000000000000000000000000006
01:25:49.084 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:DEVICE_INFORMATION_RESPONSE sequence:51204 
payload:000D6F000076A0ED0D023E3500054ED000856539090093034DCCDB7B02
01:25:49.115 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:ACKNOWLEDGEMENT sequence:51205 payload:00C1
01:25:49.115 INFO  o.o.b.plugwise.internal.Stick[:665]- Sending Plugwise 
protocol data unit: attempts: 1 MAC:000D6F000076A444 
command:POWER_INFORMATION_REQUEST sequence:0 full HEX:0012000D6F000076A444924B
01:25:49.131 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:POWER_INFORMATION_RESPONSE sequence:51205 
payload:000D6F000076A0ED0000FFFF00000000FFFED61E0005
01:25:49.162 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:ACKNOWLEDGEMENT sequence:51206 payload:00C1
01:25:49.162 INFO  o.o.b.plugwise.internal.Stick[:665]- Sending Plugwise 
protocol data unit: attempts: 1 MAC:000D6F0000D33CC5 
command:DEVICE_INFORMATION_REQUEST sequence:0 full HEX:0023000D6F0000D33CC5599A
01:25:49.177 ERROR o.o.b.plugwise.internal.Stick[:454]- Plugwise protocol 
message error: # APSRequestNodeInfo: Source MAC: 000D6F0000C3D33A# 
APSRequestNodeInfo: Destination MAC:  
01:25:49.193 ERROR o.o.b.plugwise.internal.Stick[:451]- Plugwise protocol 
header error: 000D in message 000D6F000076A444
01:25:49.224 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:DEVICE_INFORMATION_RESPONSE sequence:51206 
payload:000D6F000076A4440D023E350005DF4000856539090093034DCCDB7B02
01:25:49.240 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:ACKNOWLEDGEMENT sequence:51207 payload:00C1
01:25:49.240 INFO  o.o.b.plugwise.internal.Stick[:665]- Sending Plugwise 
protocol data unit: attempts: 1 MAC:000D6F0000D33CC5 
command:POWER_INFORMATION_REQUEST sequence:0 full HEX:0012000D6F0000D33CC5490A
01:25:49.255 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:POWER_INFORMATION_RESPONSE sequence:51207 
payload:000D6F000076A4440000FFFF00000000FFFE9ECC000D
01:25:49.287 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:ACKNOWLEDGEMENT sequence:51208 payload:00C1
01:25:49.287 INFO  o.o.b.plugwise.internal.Stick[:665]- Sending Plugwise 
protocol data unit: attempts: 1 MAC:000D6F0000D364C8 
command:DEVICE_INFORMATION_REQUEST sequence:0 full HEX:0023000D6F0000D364C869EA
01:25:49.302 ERROR o.o.b.plugwise.internal.Stick[:454]- Plugwise protocol 
message error: # APSRequestNodeInfo: Source MAC: 000D6F0000C3D33A# 
APSRequestNodeInfo: Destination MAC:  
01:25:49.333 ERROR o.o.b.plugwise.internal.Stick[:451]- Plugwise protocol 
header error: 000D in message 000D6F0000D33CC5
01:25:49.349 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:ACKNOWLEDGEMENT sequence:51209 payload:00C1
01:25:49.349 INFO  o.o.b.plugwise.internal.Stick[:665]- Sending Plugwise 
protocol data unit: attempts: 1 MAC:000D6F0000D364C8 
command:POWER_INFORMATION_REQUEST sequence:0 full HEX:0012000D6F0000D364C8797A
01:25:49.365 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:DEVICE_INFORMATION_RESPONSE sequence:51208 
payload:000D6F0000D33CC50D023E350005B3F800856539090011044DCCDB7B02
01:25:49.396 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:ACKNOWLEDGEMENT sequence:51210 payload:00C1
01:25:49.411 ERROR o.o.b.plugwise.internal.Stick[:454]- Plugwise protocol 
message error: # APSRequestNodeInfo: Source MAC: 000D6F0000C3D33A# 
APSRequestNodeInfo: Destination MAC:  
01:25:49.443 ERROR o.o.b.plugwise.internal.Stick[:451]- Plugwise protocol 
header error: 000D in message 000D6F0000D364C8
01:25:49.458 INFO  o.o.b.plugwise.internal.Stick[:398]- Parsing Plugwise 
protocol data unit: command:POWER_INFORMATION_RESPONSE sequence:51209 
payload:000D6F0000D33CC50000FFFF00000000FFFF4552000D
01:25:49.474 ERROR o.o.b.plugwise.internal.Stick[:454]- Plugwise protocol 
message error: ? 
0024C80A000D6F0000D364C80D023E3500048FA800856539090011044DCCDB7B0219F9 

I *think* it's repeatable if a modules drops out the network temporarily. i.e. 
there's a binding for it, but the stick can't see it. I'll try and do some more 
testing but the failure is not immediate once a module drop out the network.

The hardware config is fine as I'd been running Source on the same machine 
flawlessly for about a year.

Thanks,

Ian

Original issue reported on code.google.com by ianlinda...@gmail.com on 12 Feb 2013 at 3:40

GoogleCodeExporter commented 8 years ago

Original comment by kai.openhab on 12 Feb 2013 at 3:42

GoogleCodeExporter commented 8 years ago
Some further digging has shown the Plugwise bundle stops receiving serial data 
and the bundle appears to have stopped. I tried restarting it from the osgi 
command prompt but it says port in use. Trying to stop the bundle says it's not 
running.

So for some reason it appears to silently die?

Original comment by ianlinda...@gmail.com on 14 Feb 2013 at 11:08

GoogleCodeExporter commented 8 years ago
[Sorry for me seeing this bug so late. I have been been busy with the physical 
build-out of my house, and I have currently little time to spend on OH]

With respect to the Plugwise protocol you should know that it is based on 
reverse engineering efforts. There are parts of the protocol which are still 
undocumented or not analysed. There are also changes in the protocol depending 
on the firmware used by the Stick and Circles. So, most likely, your first post 
is due to a undocumented part of the protocol, or a new format of data being 
returned by the POWER_INFORMATION_RESPONSE message. I need to decode the 
response by hand to understand what it being returned.

With respect to the second post, could you investigate whether it is the Stick 
not sending serial data anymore (thus, no data on the serial port al all), or 
simply the binding trashing the data for some reason? It has been  a very long 
time since I have written the binding, but imho I think there is a problem with 
the threading/quartz jobs that make the binding tick. Again, I need to 
investigate in the future

K

Original comment by karel.go...@gmail.com on 30 Mar 2013 at 9:52

GoogleCodeExporter commented 8 years ago
unassigned to make current state more transparent

Original comment by teichsta on 21 May 2013 at 9:17

GoogleCodeExporter commented 8 years ago
Hi Ian,

I have experienced the same issue. The plugwise binding silently stops working. 
I am running Plugwise binding on Linux and the reason I have discovered was an 
active USB power management. As soon as power management was enabled and active 
the stick was no longer useable/responding.

Maybe the same applies to Windows. If you can disable power management for a 
specific USB hub or port give it a try.

Regards

Ingo

Original comment by ingo.the...@googlemail.com on 26 Jun 2013 at 8:28

GoogleCodeExporter commented 8 years ago
Ian,

were you able to try out Ingo's suggstion?

K

Original comment by karel.go...@gmail.com on 12 Sep 2013 at 7:25

GoogleCodeExporter commented 8 years ago

Original comment by teichsta on 5 Nov 2013 at 10:47

GoogleCodeExporter commented 8 years ago
This issue has been migrated to Github. If this issue id is greater than103 its 
id has been preserved on Github. You can open your issue by calling the URL 
https://github.com/openhab/openhab/issues/<issueid>. Issues with ids less or 
equal 103 new ids were created.

Original comment by teichsta on 17 Nov 2013 at 8:08

GoogleCodeExporter commented 8 years ago
see above!

Issue has been migrated to Github and should be discussed there.

Original comment by teichsta on 21 Nov 2013 at 1:51