FGFS-101 device not recognized anymore (firmware 2.5)

Add-ons Bindings
18

hi
its recognized now and all items are auto created.
however all auto created items dont show any values:

10:20:24.139 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=ApplicationUpdate, cancelled=true      MISMATCH
10:20:24.172 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 C6 
10:20:24.187 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
10:20:24.191 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 C6 
10:20:24.195 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 C6 
10:20:24.199 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 
10:20:24.253 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 10: Application update request. Node information received.
10:20:24.255 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Starting initialisation from DONE
10:20:24.257 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@270b74 already registered
10:20:24.260 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 10: Is awake with 1 messages in the wake-up queue.
10:20:24.264 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
10:20:24.269 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Wakeup during initialisation.
10:20:24.273 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - DETAILS: queue length(1), free to send(false)
10:20:24.277 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - queued packet. Queue length is 1
10:20:24.279 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 31. Queue={}
10:20:24.280 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveWakeUpEvent
10:20:24.285 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 32. Queue={}
10:20:24.288 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=RequestNodeInfo[0x60], type=Request[0x00], priority=High, dest=255, callback=0, payload=0A 
10:20:24.291 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 
10:20:24.293 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=ApplicationUpdate, cancelled=false        transaction complete!
10:20:24.295 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
10:20:24.297 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - DETAILS: Transaction complete (RequestNodeInfo:Request) success(true)
10:20:24.298 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
10:20:24.300 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - message removed from queue. Queue size 0.
10:20:24.302 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - DETAILS: queue length(0), free to send(true)
10:20:24.304 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - DETAILS try 2: stageAdvanced(false)
10:20:24.305 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: DETAILS - send RequestNodeInfo
10:20:24.308 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - queued packet. Queue length is 1
10:20:24.310 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 33. Queue={}
10:20:24.312 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 476ms/4771ms.
10:20:24.314 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 32
10:20:24.317 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0A 02 84 08 25 D4 90 
10:20:24.321 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 09 00 13 0A 02 84 08 25 D4 90 
10:20:24.334 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
10:20:24.347 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
10:20:24.351 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
10:20:24.354 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
10:20:24.358 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
10:20:24.361 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 10: Sent Data successfully placed on stack.
10:20:24.373 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 D4 00 00 04 3B 
10:20:24.379 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
10:20:24.382 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 D4 00 00 04 00 00 35 
10:20:24.386 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 D4 00 00 04 00 00 35 
10:20:24.397 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=D4 00 00 04 
10:20:24.400 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 10: SendData Request. CallBack ID = 212, Status = Transmission complete and ACK received(0)
10:20:24.403 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Starting initialisation from DONE
10:20:24.406 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@270b74 already registered
10:20:24.410 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=10, callback=212, payload=0A 02 84 08 
10:20:24.413 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=D4 00 00 04 
10:20:24.416 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=212, expected=SendData, cancelled=false        transaction complete!
10:20:24.418 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
10:20:24.421 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - DETAILS: Transaction complete (SendData:Request) success(true)
10:20:24.423 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
10:20:24.426 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 10: Went to sleep
10:20:24.429 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 10: Is sleeping
10:20:24.432 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
10:20:24.434 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 10: Response processed after 109ms/4771ms.
10:20:24.439 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 31
10:20:24.443 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 0A 91 
10:20:24.445 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 0A 91 
10:20:24.460 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 
10:20:24.465 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
10:20:24.467 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 60 01 9B 
10:20:24.470 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 60 01 9B 
10:20:24.476 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=RequestNodeInfo[0x60], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
10:20:24.480 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack.
10:20:24.484 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=RequestNodeInfo[0x60], type=Request[0x00], priority=High, dest=255, callback=0, payload=0A 
10:20:24.488 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=RequestNodeInfo[0x60], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
10:20:24.492 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=RequestNodeInfo, callback id=0, expected=ApplicationUpdate, cancelled=false      MISMATCH
10:20:24.552 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 13 00 49 84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 C6 
10:20:24.557 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
10:20:24.561 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 13 00 49 84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 C6 
10:20:24.566 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 13 00 49 84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 C6 
10:20:24.571 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 
10:20:24.576 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 10: Application update request. Node information received.
10:20:24.579 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Starting initialisation from DONE
10:20:24.591 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@270b74 already registered
10:20:24.592 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 10: Is awake with 0 messages in the wake-up queue.
10:20:24.593 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
10:20:24.594 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Wakeup during initialisation.
10:20:24.595 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - DETAILS: queue length(1), free to send(false)
10:20:24.597 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - DETAILS try 3: stageAdvanced(false)
10:20:24.598 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: DETAILS - send RequestNodeInfo
10:20:24.600 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - queued packet. Queue length is 1
10:20:24.602 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 32. Queue={}
10:20:24.603 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveWakeUpEvent
10:20:24.607 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=RequestNodeInfo[0x60], type=Request[0x00], priority=High, dest=255, callback=0, payload=0A 
10:20:24.610 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 0A 0D 04 A1 02 30 9C 60 85 8E 72 70 86 80 84 
10:20:24.612 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=ApplicationUpdate, cancelled=false        transaction complete!
10:20:24.613 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
10:20:24.615 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - DETAILS: Transaction complete (RequestNodeInfo:Request) success(true)
10:20:24.616 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
10:20:24.618 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - message removed from queue. Queue size 0.
10:20:24.619 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - DETAILS: queue length(0), free to send(true)
10:20:24.621 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - DETAILS try 4: stageAdvanced(false)
10:20:24.622 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: DETAILS - send RequestNodeInfo
10:20:24.624 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - queued packet. Queue length is 1
10:20:24.626 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 33. Queue={}
10:20:24.628 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 177ms/4771ms.
10:20:24.630 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 32
10:20:24.633 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 0A 91 
10:20:24.635 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 0A 91 
10:20:24.646 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 
10:20:24.649 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
10:20:24.650 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 60 01 9B 
10:20:24.652 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 60 01 9B 
10:20:24.654 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=RequestNodeInfo[0x60], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
10:20:24.655 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack.
10:20:24.657 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=RequestNodeInfo[0x60], type=Request[0x00], priority=High, dest=255, callback=0, payload=0A 
10:20:24.659 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=RequestNodeInfo[0x60], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
10:20:24.660 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=RequestNodeInfo, callback id=0, expected=ApplicationUpdate, cancelled=false      MISMATCH
10:20:25.627 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 10: No more messages, go back to sleep
10:20:25.629 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 10: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
10:20:25.631 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 33. Queue={}
10:20:29.641 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Too many retries. Discarding message: Message: class=RequestNodeInfo[0x60], type=Request[0x00], priority=High, dest=255, callback=0, payload=0A 
10:20:29.642 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 32
10:20:29.644 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0A 02 84 08 25 D5 91 
10:20:29.651 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 09 00 13 0A 02 84 08 25 D5 91 
10:20:29.665 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
10:20:29.670 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
10:20:29.672 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
10:20:29.674 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
10:20:29.676 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
10:20:29.677 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 10: Sent Data successfully placed on stack.
19

I haven#t processed the log fully, but from a quick look I don’t see any data received from the device that would relate to a channel. I think these packets are all associated with NIFs and wakeup management - the device hasn’t sent any actual user data I think.

I’ll process the log properly later, but I expect my first question will be for a longer log that actually has some data included, so if you can send this it might speed things up :wink:

20

Having now processed the log, there is nothing to look at so there is no surprise that there is no updates to the channels (based solely on this log).

21

Don’t know if this can be helpful in understanding the issue: I performed some “regression” tests in the last days to identify what was the last SNAPSHOT build of the zwave binding able to properly recognize the device. What I found out was that between these two builds something went awry:

  • org.openhab.binding.zwave-2.0.0-20160724.010140-136
  • org.openhab.binding.zwave-2.0.0-20160729.010130-140
    Build 136 (performed on the 24th of July) correctly recognizes the device, while build 140 (performed on the 29th of July) does not and exhibits the behavior mentioned in earlier posts.
    I could test build 137 and 138 too if deemed useful.
22

Sorry to ask a stupid question, but what is “the issue”. Above it states that this device is now discovered ok, but the channels don’t work - so do you mean that between 136 and 140 it stopped recognising the device, or channels aren’t discovered?

Since the builds you mention are all from the old repository it’s hard to trace the history - can you provide a log showing the problem please.

23

Sorry chris, I think I was too hasty (and, therefore, a little cryptic) in writing down my last post. I’ll try to better explain what I meant.
Given that:

  1. until “recent” builds, the binding was able to correctly identify the FGFS-101 device with firmware 2.5 in my possession
  2. after an accidental reset of the controller bound to the device and several updates to the zwave binding, I found myself unable to reconnect it again to the same system it was connected to just minutes before the reset because the binding was not able to recognize it

I assumed that something in the binding changed in a way that broke the correct discovery of the device and indeed what changed between the 2 builds I reported before was the entry inside the database, where the versionMax property was capped to 3.0 (while before it was unbounded) and a new entry for newer firmware versions was added for firmware version 3.2 (as requested here).
Given the now evident “peculiar” version string (25.25) of the device and the new maximum version limit (3.0) for applicability of the right database entry, I guess we cannot blame the code that compares the firmware versions and finds 25.25 to be greater than 3.0. :slight_smile:
Could this explain the problem?
I haven’t had time to test the latest versions of the binding, but I’ll do it ASAP to see if all is OK now and, if not, to collect all relevant logs. :+1:

24

I’m not sure I completely understand. Does the device get discovered at all? If it’s version 25.25, then it should be discovered as the newer (firmware 3.2) version.

What I don’t know is if version 25.25, which while I agree is peculiar, is a real version - it shows up in their documentation and is in the pepper1 database. If version 25.25 is really the same as 2.5, and not 3.2, then we will need to create a new version which is a copy of 2.5.

Let’s see what the new binding does, and if it’s not working let’s get a log so that I can understand what’s happening… Thanks.

25

Exactly that is the case … Discovery works for 25.25 … No channels get any Update.

Since i am on vacation I could not send a log yet. I will once I am back.

26

Is this using the version from yesterday?

There are now two threads on this topic so I’m getting confused about who is using what.

27

My binding Version is from Aug 12th.
There it got recognized again.
I will update to latest binding and update here when i am back from vacation

28

I can now confirm that in recent 2.0.0-SNAPSHOT versions of the binding the device is recognized again.
However, as already mentioned here, I get these strange association groups after the device is included in the network:

   "group_1": [
      "node_179_0"
    ],
    "group_2": [
      "node_177_0"
    ],
    "group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@e902fe": [
      "node_179_0"
    ],
    "group_org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup@a837a9": [
      "node_177_0"
    ],

with the result that the controller doesn’t receive flood alarm events.
Putting node_1_0 in group_1 makes it work again, although the alarm is now received on the Binary sensor 1 channel instead of the Alarm (flood) one.

29

I can’t say too much without a log during startup - my initial reaction is that the device has these nodes configured somehow…

What file is this (is it from my json storage?).

30

No, that output is from the /rest/things/zwave:xyz API call.
As I’m currently performing some experiments, I’ll retry the association from scratch and attach complete logs soon.

31

I don’t understand why the second two groups have a full class name specified. They should all by lists of strings so this is confusing me how this can happen. The code looks like this -:

                        List<String> group = new ArrayList<String>();
        ...
                        configuration.put("group_" + groupId, group);

so I don’t see how the ZWaveAssociationGroup class gets used? How are you configuring the system?

32

Here is a complete log (of course not an XML): fgfs101.log.zip.xml (110.9 KB)

Here’s what I’ve done:

  1. start from scratch with a controller that has been hard reset
  2. inclusion of the FGFS-101 device (node 2)
  3. exclusion of the device
  4. re-inclusion of the same device (node 3)

As you can see from the log, the association groups set in the device are different between the two runs:

  • node_181_0 and node_182_0 for node 2
  • node_174_0 for node 3
    They also do not include node_1_0 in both cases.
33

Thanks - I’ll try and look at this, but as I mentioned on Github, you are using a totally different format for the logging and it means I can’t process logs from you. Is there any chance you can make it more standard - otherwise it’s really going to be a lot of work for me :frowning: .

34

Me neither, I never noticed it until i updated the zwave binding to the latest snapshot and the ESH runtime we’re using to the 0.9.0b1 version… :confused:
From your code and my REST output, it seems like sometimes groupId is not an integer but an instance of org.openhab.binding.zwave.internal.protocol.ZWaveAssociationGroup. Is this possible?

35

I thought the logs would be good now… :sweat:
If by “standard” you mean like the openhab ones, I’ll try using the same conversion pattern from the openhab project, as I can see there are some differences…
Here are new logs using the OH log format: fgfs101.log-OH.zip.xml (111.3 KB) Is this ok?
In this log, I repeated the same experiment as before and the nodes are now node 4 and 5 (I didn’t reset the controller), while the “abnormal groups” are:

  • node_185_0 and node_191_0 for node 4
  • node_187_0 and node_184_0 for node 5
36

Not “sometimes” - it should never be an integer. It should be a string - always - but for some reason it’s something else in this case and I’ve no idea why or how this is possible. Maybe I need to do a better check in the binding as there’s another place where this is set…

I think it has a log of differences! :slight_smile: I should say that I quite like your formatting in that it’s easier to read visually, but it breaks the assumptions in the log reader which searches the string for the date (which you have formatted differently), and then the break to the main text which uses a - instead of your |. Maybe if you can change the last | to - and fix the formatting of the date it might work.

I’ll take a look at your new log, but probably tonight as I have to travel soon…

37

Thank you Chris, as always. :slight_smile: