Z-wave: inclusion does not work and numerous other problems

thkrebs · February 21, 2016, 11:53am

I am in a state of total confusion and disaster.
I have an AEON FGS222 and a Aeotec Z-Wave Gen5 stick. The stick is installed on my Raspberry PI which is running Openhab 1.7.0. The installed Z-Wave binding is version 1.8.0.201508211938.
The FGS222 is my first Z-Wave device.
Yesterday, I successfully included it through Habmin. However, after a couple commands the node was always reported as dead.
I tried then a couple of things: heal, delete node, remove node etc. and eventually included it back again always with the same result.
Yesterday evening I decided to stop and work on that today with a fresh mind.

I rebooted my Raspberry. After that the FG2222 node was not displayed anymore.
However, I am not even able to include it anymore (the Raspberry with the stick is positioned just before the switch < 30cm distance).
The extract from log shows the following:

2016-02-21 12:23:18.699 [DEBUG] [eController$ZWaveReceiveThread:1441]- Receive Message = 01 07 00 4A FF 01 00 00 4C
2016-02-21 12:23:18.703 [DEBUG] [b.z.i.protocol.ZWaveController:1123]- Receive queue TAKE: Length=0
2016-02-21 12:23:18.704 [DEBUG] [eController$ZWaveReceiveThread:1365]- Receive queue ADD: Length=0
2016-02-21 12:23:18.706 [DEBUG] [o.b.z.i.protocol.SerialMessage:233 ]- Assembled message buffer = 01 07 00 4A FF 01 00 00 4C
2016-02-21 12:23:18.709 [DEBUG] [b.z.i.protocol.ZWaveController:1124]- Process Message = 01 07 00 4A FF 01 00 00 4C
2016-02-21 12:23:18.711 [DEBUG] [b.z.i.protocol.ZWaveController:190 ]- Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 01 00 00
2016-02-21 12:23:18.712 [DEBUG] [.b.z.i.p.s.AddNodeMessageClass:72  ]- Add Node: Learn ready.
2016-02-21 12:23:18.718 [DEBUG] [b.z.i.protocol.ZWaveController:595 ]- Notifying event listeners: ZWaveInclusionEvent
2016-02-21 12:23:18.720 [DEBUG] [.z.internal.ZWaveActiveBinding:433 ]- ZwaveIncomingEvent
2016-02-21 12:23:18.723 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:63  ]- Sent message Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = 81 FF
2016-02-21 12:23:18.725 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:64  ]- Recv message Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 01 00 00
2016-02-21 12:23:18.727 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:65  ]- Checking transaction complete: class=AddNodeToNetwork, expected=AddNodeToNetwork, cancelled=false
2016-02-21 12:23:18.728 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:68  ]-          transaction complete!
2016-02-21 12:23:18.730 [DEBUG] [b.z.i.protocol.ZWaveController:595 ]- Notifying event listeners: ZWaveTransactionCompletedEvent
2016-02-21 12:23:18.731 [DEBUG] [.z.internal.ZWaveActiveBinding:433 ]- ZwaveIncomingEvent
2016-02-21 12:23:18.733 [DEBUG] [WaveController$ZWaveSendThread:1287]- NODE 255: Response processed after 38ms/1271ms.
2016-02-21 12:23:26.302 [DEBUG] [eController$ZWaveReceiveThread:1441]- Receive Message = 01 09 00 04 10 02 03 25 03 00 C5
2016-02-21 12:23:26.305 [DEBUG] [eController$ZWaveReceiveThread:1365]- Receive queue ADD: Length=1
2016-02-21 12:23:26.305 [DEBUG] [b.z.i.protocol.ZWaveController:1123]- Receive queue TAKE: Length=0
2016-02-21 12:23:26.309 [DEBUG] [o.b.z.i.protocol.SerialMessage:233 ]- Assembled message buffer = 01 09 00 04 10 02 03 25 03 00 C5
2016-02-21 12:23:26.311 [DEBUG] [b.z.i.protocol.ZWaveController:1124]- Process Message = 01 09 00 04 10 02 03 25 03 00 C5
2016-02-21 12:23:26.313 [DEBUG] [b.z.i.protocol.ZWaveController:190 ]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 10 02 03 25 03 00
2016-02-21 12:23:26.317 [WARN ] [ApplicationCommandMessageClass:35  ]- NODE 2: Not initialized yet, ignoring message.
2016-02-21 12:23:26.792 [DEBUG] [eController$ZWaveReceiveThread:1441]- Receive Message = 01 09 00 04 10 02 03 25 03 FF 3A
2016-02-21 12:23:26.795 [DEBUG] [eController$ZWaveReceiveThread:1365]- Receive queue ADD: Length=1
2016-02-21 12:23:26.795 [DEBUG] [b.z.i.protocol.ZWaveController:1123]- Receive queue TAKE: Length=0
2016-02-21 12:23:26.799 [DEBUG] [o.b.z.i.protocol.SerialMessage:233 ]- Assembled message buffer = 01 09 00 04 10 02 03 25 03 FF 3A
2016-02-21 12:23:26.800 [DEBUG] [b.z.i.protocol.ZWaveController:1124]- Process Message = 01 09 00 04 10 02 03 25 03 FF 3A
2016-02-21 12:23:26.802 [DEBUG] [b.z.i.protocol.ZWaveController:190 ]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 10 02 03 25 03 FF
2016-02-21 12:23:26.803 [WARN ] [ApplicationCommandMessageClass:35  ]- NODE 2: Not initialized yet, ignoring message.
2016-02-21 12:23:27.202 [DEBUG] [eController$ZWaveReceiveThread:1441]- Receive Message = 01 09 00 04 10 02 03 25 03 00 C5
2016-02-21 12:23:27.205 [DEBUG] [eController$ZWaveReceiveThread:1365]- Receive queue ADD: Length=1
2016-02-21 12:23:27.207 [DEBUG] [b.z.i.protocol.ZWaveController:1123]- Receive queue TAKE: Length=0
2016-02-21 12:23:27.209 [DEBUG] [o.b.z.i.protocol.SerialMessage:233 ]- Assembled message buffer = 01 09 00 04 10 02 03 25 03 00 C5
2016-02-21 12:23:27.211 [DEBUG] [b.z.i.protocol.ZWaveController:1124]- Process Message = 01 09 00 04 10 02 03 25 03 00 C5
2016-02-21 12:23:27.213 [DEBUG] [b.z.i.protocol.ZWaveController:190 ]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 10 02 03 25 03 00
2016-02-21 12:23:27.214 [WARN ] [ApplicationCommandMessageClass:35  ]- NODE 2: Not initialized yet, ignoring message.
2016-02-21 12:23:27.733 [DEBUG] [eController$ZWaveReceiveThread:1441]- Receive Message = 01 09 00 04 10 02 03 25 03 FF 3A
2016-02-21 12:23:27.736 [DEBUG] [eController$ZWaveReceiveThread:1365]- Receive queue ADD: Length=1
2016-02-21 12:23:27.737 [DEBUG] [b.z.i.protocol.ZWaveController:1123]- Receive queue TAKE: Length=0
2016-02-21 12:23:27.739 [DEBUG] [o.b.z.i.protocol.SerialMessage:233 ]- Assembled message buffer = 01 09 00 04 10 02 03 25 03 FF 3A
2016-02-21 12:23:27.741 [DEBUG] [b.z.i.protocol.ZWaveController:1124]- Process Message = 01 09 00 04 10 02 03 25 03 FF 3A
2016-02-21 12:23:27.743 [DEBUG] [b.z.i.protocol.ZWaveController:190 ]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 10 02 03 25 03 FF
2016-02-21 12:23:27.744 [WARN ] [ApplicationCommandMessageClass:35  ]- NODE 2: Not initialized yet, ignoring message.
2016-02-21 12:23:28.059 [DEBUG] [z.internal.ZWaveNetworkMonitor:353 ]- Network Monitor: No nodes to ping!

I am completly stuck. Any help is highly appreciated!

chris · February 21, 2016, 12:53pm

It looks like the node is already included (node 2?) so it doesn’t need to be included again…

This might be too close - they could well be overloading each other and unable to receive (this is certainly an issue people see - it may or may not be your problem).

thkrebs · February 21, 2016, 1:03pm

I still see the NODE 2: not initialized messages which seem to indicate that the node is sending out messages which are received by the “stick”. Am I right on that?
Is there any way to reset everything?
I already switched off the house fuse, rebooted my Raspberry … but. According to the sticks doc. it should have a factory reset which I do not find…
I think it would be best to start all over again.

chris · February 21, 2016, 1:37pm

Yes- it looks that way.

So, it looks like node 2 isn’t actually known by the stick - I guess somewhere along your travels you might have reset it (there is a function in HABmin 1 I think, although I might be wrong as I’ve not looked at it for a while). So the device itself still thinks its linked, but the stick doesn’t…

Take the stick out of the Pi and put it into exclusion mode (I think you hold the button down for 3 seconds - check the manual though). Then exclude the device (again, I think this is 3 presses on the button, but check the manual). This should reset the device - the led on the stick will likely do something different when the device is reset (it goes solid for a few seconds I think).

Then try and include everything again. I would simply do it from the stick - put the stick into include more, then tripple click the buton on the device again and you should see the LED on the stick change for a few seconds…

Once that’s done, put the stick back into the Pi and restart things. Check the log and see if you see a message on startup that says the number of nodes found, and what node number they are…

thkrebs · February 21, 2016, 5:44pm

Thanks for trying to help. It is really frustrating. I am new to ZWave and I have no glue what else I can try:

I removed the stick and reset it. The stick blinked as it should. So I guess it worked.
I tried inclusion from the stick (unplugged from the USB port). I didn’t get the any “blink” changes on the stick.
I tried to reset the relay node. Not sure whether I did it right. It is a double wall switch. I switched off power and as stated in the manual, I changed the position of both wall switches… is that right???

The results are now: the node is not seen in the log anymore. I tried inclusion over Habmin with the stick only…
Very frustrating

thkrebs · February 23, 2016, 7:20am

So I opened the wall switch and tried the following after resetting the AEOTEC stick to factory settings:

exclude node directly from stick
include node directly from stick

Started openhab and looked in habmin -> no node listed

Tried exclusion and inclusion from habmin (pressing now the micro button on the FGS222). Nothing.
Below I included the extract from the log showing the inclusion:
2016-02-23 08:15:55.694 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 255: Creating empty message of class = AddNodeToNetwork (0x4A), type = Request (0x00) 2016-02-23 08:15:55.697 [DEBUG] [b.z.i.protocol.ZWaveController:580 ]- Enqueueing message. Queue length = 1 2016-02-23 08:15:55.698 [DEBUG] [WaveController$ZWaveSendThread:1171]- Took message from queue for sending. Queue length = 0 2016-02-23 08:15:55.700 [DEBUG] [o.b.z.i.protocol.SerialMessage:233 ]- Assembled message buffer = 01 04 00 4A 05 B4 2016-02-23 08:15:55.701 [DEBUG] [WaveController$ZWaveSendThread:1228]- NODE 255: Sending REQUEST Message = 01 04 00 4A 05 B4 2016-02-23 08:15:55.795 [DEBUG] [eController$ZWaveReceiveThread:1441]- Receive Message = 01 07 00 4A FF 06 00 00 4B 2016-02-23 08:15:55.798 [DEBUG] [eController$ZWaveReceiveThread:1365]- Receive queue ADD: Length=1 2016-02-23 08:15:55.798 [DEBUG] [b.z.i.protocol.ZWaveController:1123]- Receive queue TAKE: Length=0 2016-02-23 08:15:55.801 [DEBUG] [o.b.z.i.protocol.SerialMessage:233 ]- Assembled message buffer = 01 07 00 4A FF 06 00 00 4B 2016-02-23 08:15:55.803 [DEBUG] [b.z.i.protocol.ZWaveController:1124]- Process Message = 01 07 00 4A FF 06 00 00 4B 2016-02-23 08:15:55.804 [DEBUG] [b.z.i.protocol.ZWaveController:190 ]- Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 06 00 00 2016-02-23 08:15:55.806 [DEBUG] [.b.z.i.p.s.AddNodeMessageClass:90 ]- Add Node: Done. 2016-02-23 08:15:55.808 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:63 ]- Sent message Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = 05 2016-02-23 08:15:55.810 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:64 ]- Recv message Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 06 00 00 2016-02-23 08:15:55.811 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:65 ]- Checking transaction complete: class=AddNodeToNetwork, expected=AddNodeToNetwork, cancelled=false 2016-02-23 08:15:55.812 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:68 ]- transaction complete! 2016-02-23 08:15:55.814 [DEBUG] [b.z.i.protocol.ZWaveController:595 ]- Notifying event listeners: ZWaveTransactionCompletedEvent 2016-02-23 08:15:55.815 [DEBUG] [.z.internal.ZWaveActiveBinding:433 ]- ZwaveIncomingEvent 2016-02-23 08:15:55.816 [DEBUG] [WaveController$ZWaveSendThread:1287]- NODE 255: Response processed after 113ms/319ms.

I would be interested whether there any traces from the node I to be included?