Closed GoogleCodeExporter closed 9 years ago
GoogleCodeExporter
commented
9 years ago Any idea, Karel?
@Ingo: In general I would not recommend to use OpenJDK, but rather Oracle
JavaSE Embedded.Original comment by kai.openhab on 16 Sep 2013 at 7:17
GoogleCodeExporter
commented
9 years ago Original comment by kai.openhab on 16 Sep 2013 at 7:18
GoogleCodeExporter
commented
9 years ago Ingo,
Did you recently upgrade the firmware of the Circle(+)s?
the 000D protocol header error is due to the fact that the Plugwise protocol is
not 100% reverse engineered, and sometimes the devices send back that has to be
thrown away for that reason. At first sight the binding seems to work because
it is polling the devices for "role profiles", doing device calibration, and it
is getting back data from the devices.
The last message in the log is the last part of the role profile "call" in the
network - It can be identified by the FFFFF..FFF01 in the HEX string (the Stick
returns a list of devices it sees, and the last address in that list is FFF.FFF)
You do not have any other logging info thereafter? Can you also share your item
definitions? When the network is "set up" and the "role call" has been
completed, the binding basically goes into its regular "mode",e.g. it will now
depend on what you configured in the items file in terms of what you will
receive from the network, e.g. how frequently do you poll for data etc..
If nothing would be wrong with the items definitions, then it could be related
to the serial port
[I have not tested the PW binding myself with 1.3 due to lack of time, but I
see no reason why it would not work anymore]
K
Original comment by karel.go...@gmail.com on 16 Sep 2013 at 7:53
GoogleCodeExporter
commented
9 years ago Hi Karel,
I didn't upgrade the firmware of my Circle(+)s since I bought them in April
2013. There is no more logging happening regarding the Plugwise Binding as
shown in my first post. Absolute silence after the last message.
Here are my definitions.
openhab.cfg
---
############################## Plugwise Binding
#######################################
# "stick" is reserved plug wise id
plugwise:stick.port=/dev/ttyUSB0
# "circleplus" is reserved plug wise id
plugwise:circleplus.mac=000D6F0002588E2A
plugwise:datacenter.mac=000D6F0002778CE1
---
default.items
---
/* Plugwise */
Group Wattage_Data_Center_Chart (Wattage)
Number Wattage_Data_Center "Server [%.1f W]" <plugwise>
(Wattage_Data_Center_Chart) { plugwise="[datacenter:power:10]" }
---
I doubt that the problem is related to the serial port. As said in my first
post switching back to openHAB 1.2 the Plugwise Binding is running fine. And I
can query the Circles from CLI with python-plugwise
(https://bitbucket.org/hadara/python-plugwise/wiki/Home).
Regards
IngoOriginal comment by ingo.the...@googlemail.com on 17 Sep 2013 at 10:50
GoogleCodeExporter
commented
9 years ago Ingo
the code of the binding has not changed going from 1.2 to 1.3, so the source of
the problem must indeed be external to the binding itself. I will try to test
my own config under 1.3 and see what happens. (I run OH on Mac OS X). It is
strange that the serial connection seems to work for a little while before
dying. Does it always die at the same moment? Can you try to reduce the polling
interval and check what happens?
KarelOriginal comment by karel.go...@gmail.com on 17 Sep 2013 at 12:00
GoogleCodeExporter
commented
9 years ago Hi Karel,
it always dies at the same moment. I have reduced the polling from 10 to 3 but
nothing changed.
Regards
IngoOriginal comment by ingo.the...@googlemail.com on 17 Sep 2013 at 1:27
GoogleCodeExporter
commented
9 years ago Mhhh.. do you happen to use the serial binding as well by chance? And does that
one work?
I have compared the source of the serial binding with the serial code in the
plugwise binding and they are very similar... still. and they should be,
because the serial 'core' of the plug wise binding is based on the serial
binding. If the issue would also exist with the serial binding, then we know
that it is related to the nrjavaserial library used by both bindings.
I will check everything to make sure it is not an issue with the threading
engine in the binding either....
KOriginal comment by karel.go...@gmail.com on 17 Sep 2013 at 2:18
GoogleCodeExporter
commented
9 years ago Sorry to say, but I am not using the serial binding. And I have nothing at home
to give it a try.Original comment by ingo.the...@googlemail.com on 18 Sep 2013 at 5:44
GoogleCodeExporter
commented
9 years ago Hi,
while investigating the problem further I stumbled across the following.
Here is what I did:
1. connected to the OSGI console
telnet localhost 5555)
2. uninstalled the plugwise bundle
uninstall 273
3. installed the bundle again
install file:/opt/openhab/addons/org.openhab.binding.plugwise-1.3.1.jar)
4. start the bundle
start 286
After the OSGI console start I get the following error in the openhab.log.
---
11:19:45.375 ERROR o.o.b.plugwise.internal.Stick[:120]- Failed to initialize
Plugwise stick: Serial port '/dev/ttyUSB0' could not be found. Available ports
are:
11:19:45.378 ERROR o.o.b.p.internal.CirclePlus[:106]- Error scheduling a Quartz
Job
---
The serial port is still present:
crw-rw---T 1 root dialout 188, 0 Sep 20 11:12 /dev/ttyUSB0
So I checked if any process is using the serial port. The out put from the
'lsof | grep ttyUSB' is attached.
These are hell of a lot entries!
And I think openHAB should release the resource after uninstalling the bundle,
or am I wrong?Original comment by ingo.the...@googlemail.com on 20 Sep 2013 at 9:38
Attachments:
GoogleCodeExporter
commented
9 years ago Ingo
This is indeed a bug in the binding - the deactivate() is missing as well as a
removeConfigurations()
KOriginal comment by karel.go...@gmail.com on 20 Sep 2013 at 10:42
GoogleCodeExporter
commented
9 years ago Hi Karel,
should I open a new issue for the missing deactivate() and
removeConfigurations() calls?
IOriginal comment by ingo.the...@googlemail.com on 23 Sep 2013 at 10:24
GoogleCodeExporter
commented
9 years ago Nope - That is not necessary - I will couple this with the serial port test
under post-1.3Original comment by karel.go...@gmail.com on 23 Sep 2013 at 10:56
GoogleCodeExporter
commented
9 years ago Ingo
Just did a test on OH 1.3 with my Stick/setup and I can confirm everything is
running fine, including all the polling and so forth. /me think this has to due
with the serial port driver on your host platform (mine is Mac OS X)
KOriginal comment by karel.go...@gmail.com on 23 Sep 2013 at 7:52
GoogleCodeExporter
commented
9 years ago So shall this issue be rejected then?Original comment by kai.openhab on 24 Sep 2013 at 3:45
GoogleCodeExporter
commented
9 years ago Karel
when you say 'serial port driver' do you mean the nrjavaserial library used by
the binding or the Linux kernel serial port driver?
Is there anything I can do to trace down the problem on my own?Original comment by ingo.the...@googlemail.com on 24 Sep 2013 at 6:57
GoogleCodeExporter
commented
9 years ago The linux kernel driver or the driver you installed at the OS level to support
the Plugwise device. I can not find of another reason since it works OK in my
installation (unmodified OH distro)
the resource release I can currently not test my solution as the OSGi console
is behaving weirdly
KOriginal comment by karel.go...@gmail.com on 24 Sep 2013 at 8:39
GoogleCodeExporter
commented
9 years ago Karel I just want say thank you and I really appreciate your time you spent on
my issue.
Lets recapitulate what we got so far.
- The Plugwise Binding hasn't changed from openHAB 1.2 to 1.3
- The Plugwise Binding is using the nrjavaserial-3.8.8.jar both in openHAB 1.2
and openHAB 1.3
- I am running openHAB on a Debian testing/unstable Server, Kernel 3.11 with
Java(TM) Oracle SE Runtime Environment (build 1.7.0_40-b43)
- I have installed openHAB 1.2 AND openHAB 1.3 (/opt/openhab_1.2;
/opt/openhab_1.3)
- In openHAB 1.2 the Plugwise Binding is working
- In openHAB 1.3 the Plugwise Binding is NOT working (silently dies)
Is there any way to get some logging from the nrjavaserial-3.8.8.jar?
I
Original comment by ingo.the...@googlemail.com on 24 Sep 2013 at 10:19
GoogleCodeExporter
commented
9 years ago I am not an expert in the nrjavaserial lib. This is an excerpt of what I have
in the openhab.log and event.log
20:13:22.508 DEBUG o.o.b.plugwise.internal.Stick[:195]- Serial port
'/dev/tty.usbserial-A700dr4E' has been found.
20:13:22.547 DEBUG o.o.b.p.i.PlugwiseBinding[:118]- Plugwise added Stick
connected to serial port /dev/tty.usbserial-A700dr4E
20:13:22.556 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC: command:INITIALISE_REQUEST sequence:0 full
HEX:000AB43C
20:13:22.578 DEBUG o.o.b.p.i.PlugwiseBinding[:175]- Plugwise added Circle+ with
MAC address: 000D6F000099675B
20:13:22.631 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:48 payload:00C1
20:13:22.665 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:INITIALISE_RESPONSE sequence:48
payload:000D6F0000B84DAB0101DE0D6F000099675B39DEFF
20:13:22.736 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000099675B
command:DEVICE_INFORMATION_REQUEST sequence:0 full HEX:0023000D6F000099675B00E9
20:13:22.769 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:49 payload:00C1
20:13:22.770 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000099675B
command:DEVICE_CALIBRATION_REQUEST sequence:0 full HEX:0026000D6F000099675B5383
20:13:22.792 ERROR o.o.b.plugwise.internal.Stick[:473]- Plugwise protocol
message error: # APSRequestNodeInfo: Source MAC: 000D6F0000B84DAB#
APSRequestNodeInfo: Destination MAC:
20:13:22.814 ERROR o.o.b.plugwise.internal.Stick[:470]- Plugwise protocol
header error: 000D in message 000D6F000099675B
20:13:22.838 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:DEVICE_INFORMATION_RESPONSE sequence:49
payload:000D6F000099675B0D0980050005411801856539090088024E0843A901
20:13:22.861 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:50 payload:00C1
20:13:22.869 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000099675B command:CLOCK_SET_REQUEST
sequence:0 full HEX:0016000D6F000099675B0D098005FFFFFFFF120D16003118
20:13:22.880 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000099675B
command:DEVICE_ROLECALL_REQUEST sequence:0 full HEX:0018000D6F000099675B00E32A
20:13:22.885 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:DEVICE_CALIBRATION_RESPONSE sequence:50
payload:000D6F000099675B3F7E3602B61798253DCC1F3700000000
20:13:22.897 DEBUG o.o.c.i.items.ItemRegistryImpl[:157]- Item provider
'GenericItemProvider' has been added.
20:13:22.908 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:51 payload:00C1
20:13:22.934 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:51
payload:00D7000D6F000099675B
20:13:22.975 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:52 payload:00C1
20:13:22.980 DEBUG o.o.b.plugwise.internal.Stick[:551]- Plugwise Unknown
Acknowledgement message Extension
20:13:23.002 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:DEVICE_ROLECALL_RESPONSE sequence:52
payload:000D6F000099675B000D6F000098E9B800
20:13:23.044 DEBUG o.o.b.p.internal.CirclePlus[:149]- Added a Circle with MAC
000D6F000098E9B8 to the cache
20:13:23.087 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000098E9B8
command:DEVICE_INFORMATION_REQUEST sequence:0 full HEX:0023000D6F000098E9B82603
20:13:23.120 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:53 payload:00C1
20:13:23.121 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000098E9B8
command:DEVICE_CALIBRATION_REQUEST sequence:0 full HEX:0026000D6F000098E9B87569
20:13:23.138 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000099675B
command:DEVICE_ROLECALL_REQUEST sequence:0 full HEX:0018000D6F000099675B01F30B
20:13:23.143 ERROR o.o.b.plugwise.internal.Stick[:473]- Plugwise protocol
message error: # APSRequestNodeInfo: Source MAC: 000D6F0000B84DAB#
APSRequestNodeInfo: Destination MAC:
20:13:23.165 ERROR o.o.b.plugwise.internal.Stick[:470]- Plugwise protocol
header error: 000D in message 000D6F000098E9B8
20:13:23.187 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:54 payload:00C1
20:13:23.213 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:55 payload:00C1
20:13:23.235 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:DEVICE_ROLECALL_RESPONSE sequence:55
payload:000D6F000099675BFFFFFFFFFFFFFFFF01
20:13:23.411 DEBUG o.o.m.p.i.PersistenceModelActivator[:43]- Registered
'persistence' configuration parser
20:13:23.424 INFO o.o.m.c.i.ModelRepositoryImpl[:99]- Loading model
'demo.items'
20:13:23.565 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:DEVICE_INFORMATION_RESPONSE sequence:53
payload:000D6F000098E9B800049FDE0005476801856539090088024E0844C202
20:13:23.572 DEBUG o.o.m.i.i.GenericItemProvider[:154]- Read items from model
'demo.items'
20:13:23.586 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000099675B
command:POWER_INFORMATION_REQUEST sequence:0 full HEX:0012000D6F000099675B1079
20:13:23.609 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:DEVICE_CALIBRATION_RESPONSE sequence:54
payload:000D6F000098E9B83F7DC3DBB61B661A3D63B08800000000
20:13:23.631 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:56 payload:00C1
20:13:23.659 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:POWER_INFORMATION_RESPONSE sequence:56
payload:000D6F000099675B00020013000006A9000000000000
and then these at the power:interval
20:13:38.587 DEBUG o.o.b.plugwise.internal.Stick[:684]- Sending Plugwise
protocol data unit: attempts: 1 MAC:000D6F000099675B
command:POWER_INFORMATION_REQUEST sequence:0 full HEX:0012000D6F000099675B1079
20:13:38.601 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:57 payload:00C1
20:13:38.815 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:POWER_INFORMATION_RESPONSE sequence:57
payload:000D6F000099675B00020013000006CD00000000000B
20:13:38.878 DEBUG o.o.b.plugwise.internal.Stick[:417]- Parsing Plugwise
protocol data unit: command:ACKNOWLEDGEMENT sequence:57 payload:00E1
yielding these kind of Item updates
2013-09-23 20:15:10 - wattage state updated to 4.447669
2013-09-23 20:15:12 - wattage state updated to 4.447669
2013-09-23 20:15:27 - wattage state updated to 6.565218
Original comment by karel.go...@gmail.com on 24 Sep 2013 at 10:29
GoogleCodeExporter
commented
9 years ago Hi Karel,
I've got interesting news regarding the issue.
I found another user with the same problem when he switched to openHAB 1.3
(http://knx-user-forum.de/openhab/29502-plugwise.htm (German only)).
A simple touch command on the items definition file puts the Plugwise Binding
back to work! You have to do this every time you restart openHAB. It's a little
dirty workaround for every user affected by this.
Hope you can find the root cause with this new information. Or maybe Kai has
some idea what change in openHAB could have caused such a problem.
I
Original comment by ingo.the...@googlemail.com on 25 Sep 2013 at 1:46
GoogleCodeExporter
commented
9 years ago root cause found, will produce a fix shortlyOriginal comment by karel.go...@gmail.com on 8 Oct 2013 at 8:03
GoogleCodeExporter
commented
9 years ago Should be fixed with https://github.com/openhab/openhab/pull/40Original comment by kai.openhab on 13 Oct 2013 at 6:42
GoogleCodeExporter
commented
9 years ago Test successful. Everything is working as expected.
Thx!
IOriginal comment by ingo.the...@googlemail.com on 14 Oct 2013 at 6:09
Original issue reported on code.google.com by
ingo.the...@googlemail.comon 16 Sep 2013 at 6:00