[SOLVED] Plugwise error: Plugwise protocol message error: PutFifoUnicast

Hi there,

Just started with openhab and trying to figure out how things works… It’s a pretty steap learning curve :blush:
This is my config in config:list:


Pid: org.openhab.plugwise
BundleLocation: mvn:org.openhab.binding/org.openhab.binding.plugwise/1.9.0
Properties:
droger.mac = 000D6F00004BE253
droger.type = circleplus
service.pid = org.openhab.plugwise
stick.interval = 150
stick.port = /dev/ttyUSB0
wasmaschine.mac = 000D6F0000599580
wasmaschine.type = circle

but when it’s starting (after reboot) I only get error messages:

2017-06-04 22:57:15.665 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Removing from sentQueue: Plugwise Message [type=POWER_INFORMATION_REQUEST, MAC=000D6F00004BE253, SeqNr=75, payload=, retrycount=1]
2017-06-04 22:57:15.783 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Sending: Plugwise Message [type=POWER_INFORMATION_REQUEST, MAC=000D6F0000599580, SeqNr=0, payload=, retrycount=1] as 0012000D6F0000599580899D
2017-06-04 22:57:15.817 [ERROR] [nhab.binding.plugwise.internal.Stick] - Plugwise protocol message error: PutFifoUnicast 23 : Handle 76 : 000D6F0000599580
2017-06-04 22:57:15.820 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Received message: command:ACKNOWLEDGEMENT sequence:76 payload:00C1
2017-06-04 22:57:15.821 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to acknowledgedQueue: Plugwise Message [type=ACKNOWLEDGEMENT, MAC=, SeqNr=76, payload=00C1, retrycount=0]
2017-06-04 22:57:15.821 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Removing from acknowledgedQueue: Plugwise Message [type=ACKNOWLEDGEMENT, MAC=, SeqNr=76, payload=00C1, retrycount=0]
2017-06-04 22:57:15.824 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to sentQueue: Plugwise Message [type=POWER_INFORMATION_REQUEST, MAC=000D6F0000599580, SeqNr=76, payload=, retrycount=1]
2017-06-04 22:57:15.845 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Received message: command:POWER_INFORMATION_RESPONSE sequence:76 payload:000D6F0000599580000000000000000600000000000E
2017-06-04 22:57:15.846 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to receivedQueue: Plugwise Message [type=POWER_INFORMATION_RESPONSE, MAC=000D6F0000599580, SeqNr=76, payload=000D6F000059958000000000000
0000600000000000E, retrycount=0]
2017-06-04 22:57:15.851 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Removing from sentQueue: Plugwise Message [type=POWER_INFORMATION_REQUEST, MAC=000D6F0000599580, SeqNr=76, payload=, retrycount=1]
2017-06-04 22:57:25.585 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to sendQueue: Plugwise Message [type=CLOCK_GET_REQUEST, MAC=000D6F00004BE253, SeqNr=0, payload=, retrycount=0]
2017-06-04 22:57:25.586 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to sendQueue: Plugwise Message [type=POWER_INFORMATION_REQUEST, MAC=000D6F00004BE253, SeqNr=0, payload=, retrycount=0]
2017-06-04 22:57:25.587 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Sending: Plugwise Message [type=CLOCK_GET_REQUEST, MAC=000D6F00004BE253, SeqNr=0, payload=, retrycount=1] as 003E000D6F00004BE2532B46
2017-06-04 22:57:25.588 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to sendQueue: Plugwise Message [type=CLOCK_GET_REQUEST, MAC=000D6F0000599580, SeqNr=0, payload=, retrycount=0]
2017-06-04 22:57:25.589 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to sendQueue: Plugwise Message [type=POWER_INFORMATION_REQUEST, MAC=000D6F0000599580, SeqNr=0, payload=, retrycount=0]
2017-06-04 22:57:25.591 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to sendQueue: Plugwise Message [type=DEVICE_INFORMATION_REQUEST, MAC=000D6F00004BE253, SeqNr=0, payload=, retrycount=0]
2017-06-04 22:57:25.592 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to sendQueue: Plugwise Message [type=DEVICE_INFORMATION_REQUEST, MAC=000D6F0000599580, SeqNr=0, payload=, retrycount=0]
2017-06-04 22:57:25.618 [ERROR] [nhab.binding.plugwise.internal.Stick] - Plugwise protocol message error: PutFifoUnicast 69 : Handle 77 : 000D6F00004BE253
2017-06-04 22:57:25.621 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Received message: command:ACKNOWLEDGEMENT sequence:77 payload:00C1
2017-06-04 22:57:25.623 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to acknowledgedQueue: Plugwise Message [type=ACKNOWLEDGEMENT, MAC=, SeqNr=77, payload=00C1, retrycount=0]
2017-06-04 22:57:25.624 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Removing from acknowledgedQueue: Plugwise Message [type=ACKNOWLEDGEMENT, MAC=, SeqNr=77, payload=00C1, retrycount=0]
2017-06-04 22:57:25.626 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to sentQueue: Plugwise Message [type=CLOCK_GET_REQUEST, MAC=000D6F00004BE253, SeqNr=77, payload=, retrycount=1]
2017-06-04 22:57:25.762 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Received message: command:CLOCK_GET_RESPONSE sequence:77 payload:000D6F00004BE2531439190601457A
2017-06-04 22:57:25.765 [DEBUG] [nhab.binding.plugwise.internal.Stick] - Adding to receivedQueue: Plugwise Message [type=CLOCK_GET_RESPONSE, MAC=000D6F00004BE253, SeqNr=77, payload=000D6F00004BE2531439190601457A, ret
rycount=0]

and on and on and on :smile:
Is it a config thing? or perhaps something else?
please advise

greetings from holland

This is what I see in the event log

pi@openhab:/etc/openhab2/rules $ tail -f /var/log/openhab2/events.log
2017-06-04 23:12:56.990 [ItemStateChangedEvent ] - Wasmachine_Power_Stamp changed from 2017-06-04T23:12:45.843+0200 to 2017-06-04T23:12:56.973+0200
2017-06-04 23:12:57.575 [ItemStateChangedEvent ] - Droger_Real_Time_Clock changed from 2000-01-04T01:53:56.000+0100 to 2000-01-04T01:54:56.000+0100
2017-06-04 23:13:05.712 [ItemStateChangedEvent ] - Droger_Power_Stamp changed from 2017-06-04T23:12:56.652+0200 to 2017-06-04T23:13:05.693+0200
2017-06-04 23:13:05.857 [ItemStateChangedEvent ] - Wasmachine_Power_Stamp changed from 2017-06-04T23:12:56.973+0200 to 2017-06-04T23:13:05.839+0200
2017-06-04 23:13:10.833 [ItemStateChangedEvent ] - Droger_Clock changed from 21:12:56 to 21:13:10
2017-06-04 23:13:10.980 [ItemStateChangedEvent ] - Wasmachine_Clock changed from 00:54:55 to 00:55:09
2017-06-04 23:13:15.718 [ItemStateChangedEvent ] - Droger_Power_Stamp changed from 2017-06-04T23:13:05.693+0200 to 2017-06-04T23:13:15.700+0200
2017-06-04 23:13:15.867 [ItemStateChangedEvent ] - Wasmachine_Power_Stamp changed from 2017-06-04T23:13:05.839+0200 to 2017-06-04T23:13:15.850+0200
2017-06-04 23:13:25.834 [ItemStateChangedEvent ] - Droger_Clock changed from 21:13:10 to 21:13:25
2017-06-04 23:13:25.916 [ItemStateChangedEvent ] - Droger_Power_Stamp changed from 2017-06-04T23:13:15.700+0200 to 2017-06-04T23:13:25.900+0200
2017-06-04 23:13:26.161 [ItemStateChangedEvent ] - Wasmachine_Clock changed from 00:55:09 to 00:55:24

Where do you see error messages? :grinning:

You have set openHAB or one of your bindings to debug mode (http://docs.openhab.org/administration/logging.html#defining-what-to-log), so it is pretty normal to see tons of messages.
Set that back to info mode and you should be fine. It seems like your system is working pretty fine …

Haha awesome…

I see the settings was defined as TRACE… I will continue my configuration…
Thanks you so much…

log4j.logger.org.openhab.binding.plugwise = TRACE
log4j.logger.org.openhab.binding.mysensors = DEBUG
log4j.logger.org.openhab.plugwise = INFO