search

dresden-elektronik / deconz-rest-plugin

deCONZ REST-API plugin to control ZigBee devices
BSD 3-Clause "New" or "Revised" License
1.9k stars 502 forks source link

Xiaomi curtain marked as Zombie, but still sending reports #849

Closed ebaauw closed 5 years ago

ebaauw commented 6 years ago

Running v2.05.40 with 0x26230500, but I think I saw the same symptoms on v2.05.39. deCONZ marks the Xiaomi Aqara curtain controller lumi.curtain as zombie (red node), even though it's still sending Xiaomi special attribute reports.

To me this smells like routing issues, but I'm running firmware 23. Unicast commands send to the controller don't seem to arrive - at least the controller isn't reacting to them. I have yet to try and group the controller, so I cannot tell if it reacts to groupcast commands.

$ journalctl -a | grep -i -e 0x6663 -e 0x00158d0002834c6c -e /lights/327
Oct 11 19:35:19 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":false}
Oct 11 19:35:19 pi2 deCONZ[17646]: 19:35:19:279 0x6663 seems to be a zombie recv errors 10
Oct 11 19:35:19 pi2 deCONZ[17646]: 19:35:19:280 LightNode removed 0x00158d0002834c6c
Oct 11 19:35:19 pi2 deCONZ[17646]: 19:35:19:281 Node zombie state changed 0x00158d0002834c6c
Oct 11 19:36:20 pi2 deCONZ[17646]: 19:36:16:094 APS-DATA.request id: 101, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 5 len: 5 tx.options 0x00
Oct 11 19:37:02 pi2 deCONZ[17646]: 19:36:55:622 APS-DATA.request id: 127, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 6 len: 5 tx.options 0x00
Oct 11 19:38:01 pi2 deCONZ[17646]: 19:37:55:998 APS-DATA.request id: 47, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 1 len: 5 tx.options 0x00
Oct 11 19:38:44 pi2 dc_eventlog[691]: /lights/327/state: {"bri":0}
Oct 11 19:38:44 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":true}
Oct 11 19:38:44 pi2 dc_eventlog[691]: /lights/327/state: {"on":false}
Oct 11 19:38:49 pi2 deCONZ[17646]: 19:38:44:695 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 135, rssi: -74
Oct 11 19:38:49 pi2 deCONZ[17646]: 19:38:44:695 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 11 19:38:49 pi2 deCONZ[17646]: 19:38:44:695 0x00158D0002834C6C extract Xiaomi special
Oct 11 19:39:03 pi2 deCONZ[17646]: 19:38:58:327 APS-DATA.request id: 219, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0005, ep: 0x00 -> 0x00 queue: 6 len: 3 tx.options 0x04
Oct 11 19:39:11 pi2 deCONZ[17646]: 19:39:11:335 APS-DATA.request id: 29, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0006, ep: 0x01 -> 0x01 queue: 1 len: 5 tx.options 0x00
Oct 11 19:39:18 pi2 deCONZ[17646]: 19:39:17:953 0x00158D0002834C6C error APSDE-DATA.confirm: 0xA7 on task
Oct 11 19:39:18 pi2 deCONZ[17646]: 19:39:18:135 APS-DATA.request id: 95, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 5 len: 5 tx.options 0x00
Oct 11 19:39:27 pi2 deCONZ[17646]: 19:39:24:684 0x00158D0002834C6C error APSDE-DATA.confirm: 0xA7 on task
Oct 11 19:39:46 pi2 deCONZ[17646]: 19:39:39:237 APS-DATA.request id: 1, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0004, ep: 0x01 -> 0x01 queue: 6 len: 4 tx.options 0x00
Oct 11 19:39:46 pi2 deCONZ[17646]: 19:39:45:675 0x00158D0002834C6C error APSDE-DATA.confirm: 0xA7 on task
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:30:689 APS-DATA.request id: 98, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0005, ep: 0x00 -> 0x00 queue: 5 len: 3 tx.options 0x04
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:32:665 APS-DATA.request id: 109, addrmode: 0x02, addr: 0x6663, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 6 len: 11 tx.options 0x04
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:32:665 APS-DATA.request id: 110, addrmode: 0x02, addr: 0x6663, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 7 len: 5 tx.options 0x04
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:32:665 APS-DATA.request id: 111, addrmode: 0x02, addr: 0x6663, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 8 len: 5 tx.options 0x04
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:32:665 APS-DATA.request id: 112, addrmode: 0x02, addr: 0x6663, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 9 len: 5 tx.options 0x04
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:32:666 APS-DATA.request id: 113, addrmode: 0x02, addr: 0x6663, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 10 len: 7 tx.options 0x04
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:32:666 APS-DATA.request id: 114, addrmode: 0x02, addr: 0x6663, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 11 len: 5 tx.options 0x04
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:32:666 APS-DATA.request id: 115, addrmode: 0x02, addr: 0x6663, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 12 len: 11 tx.options 0x04
Oct 11 19:40:32 pi2 deCONZ[17646]: 19:40:32:666 APS-DATA.request id: 116, addrmode: 0x02, addr: 0x6663, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 13 len: 7 tx.options 0x04
Oct 11 19:40:42 pi2 deCONZ[17646]: 19:40:39:550 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 65 s
Oct 11 19:40:42 pi2 deCONZ[17646]: 19:40:40:011 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 65 s
Oct 11 19:40:42 pi2 deCONZ[17646]: 19:40:40:298 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 66 s
Oct 11 19:40:42 pi2 deCONZ[17646]: 19:40:40:968 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 66 s
Oct 11 19:40:42 pi2 deCONZ[17646]: 19:40:41:738 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 67 s
Oct 11 19:40:42 pi2 deCONZ[17646]: 19:40:42:238 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 68 s
Oct 11 19:40:43 pi2 deCONZ[17646]: 19:40:42:829 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 68 s
Oct 11 19:41:07 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":false}
Oct 11 19:41:11 pi2 deCONZ[17646]: 19:41:07:511 0x6663 seems to be a zombie recv errors 12
Oct 11 19:41:11 pi2 deCONZ[17646]: 19:41:07:512 LightNode removed 0x00158d0002834c6c
Oct 11 19:41:11 pi2 deCONZ[17646]: 19:41:07:512 Node zombie state changed 0x00158d0002834c6c
Oct 11 19:42:14 pi2 deCONZ[17646]: 19:42:12:703 APS-DATA.request id: 46, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 6 len: 5 tx.options 0x00
Oct 11 19:45:01 pi2 deCONZ[17646]: 19:45:01:125 APS-DATA.request id: 191, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 6 len: 5 tx.options 0x00
Oct 11 19:46:11 pi2 deCONZ[17646]: 19:46:09:278 APS-DATA.request id: 144, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x00
Oct 11 19:47:43 pi2 deCONZ[17646]: 19:47:37:065 APS-DATA.request id: 245, addrmode: 0x02, addr: 0x6663, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 5 len: 5 tx.options 0x00
Oct 11 19:47:43 pi2 dc_eventlog[691]: /lights/327/state: {"bri":0}
Oct 11 19:47:43 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":true}
Oct 11 19:47:43 pi2 dc_eventlog[691]: /lights/327/state: {"on":false}
Oct 11 19:47:51 pi2 deCONZ[17646]: 19:47:43:715 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 255, rssi: -58
Oct 11 19:47:51 pi2 deCONZ[17646]: 19:47:43:715 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 11 19:47:51 pi2 deCONZ[17646]: 19:47:43:715 0x00158D0002834C6C extract Xiaomi special
ebaauw commented 6 years ago

@manup, I think I've pinpointed the issue. The RaspBee seems to lose the route to the controller when receiving a Route Request. This would explain why resetting the RaspBee fixes the situation.

The controller issues a Route Request broadcast for the coordinator at 10:40:11:

Frame 99281: 125 bytes on wire (1000 bits), 125 bytes captured (1000 bits) on interface 0
Ethernet II, Src: Raspberr_3b:e8:df (b8:27:eb:3b:e8:df), Dst: Apple_ca:3b:53 (a4:5e:60:ca:3b:53)
Internet Protocol Version 4, Src: 192.168.76.81, Dst: 192.168.76.41
User Datagram Protocol, Src Port: 47105, Dst Port: 17754
ZigBee Encapsulation Protocol, Channel: 25, Length: 51
IEEE 802.15.4 Data, Dst: Broadcast, Src: 0x6663
    Frame Control Field: 0x8841, Frame Type: Data, PAN ID Compression, Destination Addressing Mode: Short/16-bit, Frame Version: IEEE Std 802.15.4-2003, Source Addressing Mode: Short/16-bit
    Sequence Number: 12
    Destination PAN: 0xe8dd
    Destination: 0xffff
    Source: 0x6663
    [Extended Source: Jennic_00:02:83:4c:6c (00:15:8d:00:02:83:4c:6c)]
    [Origin: 29]
    Frame Check Sequence (TI CC24xx format): FCS OK
ZigBee Network Layer Command, Dst: Broadcast, Src: 0x6663
    Frame Control Field: 0x1209, Frame Type: Command, Discover Route: Suppress, Security, Extended Source Command
    Destination: 0xfffc
    Source: 0x6663
    Radius: 30
    Sequence Number: 168
    Extended Source: Jennic_00:02:83:4c:6c (00:15:8d:00:02:83:4c:6c)
    ZigBee Security Header
    Command Frame: Route Request
        Command Identifier: Route Request (0x01)
        Command Options: 0x00, Many-to-One Discovery: Not Many-to-One
        Route ID: 10
        Destination: 0x0000
        Path Cost: 0

The coordinator reponds with a Route Reply:

Frame 99282: 151 bytes on wire (1208 bits), 151 bytes captured (1208 bits) on interface 0
Ethernet II, Src: Raspberr_3b:e8:df (b8:27:eb:3b:e8:df), Dst: Apple_ca:3b:53 (a4:5e:60:ca:3b:53)
Internet Protocol Version 4, Src: 192.168.76.81, Dst: 192.168.76.41
User Datagram Protocol, Src Port: 47105, Dst Port: 17754
ZigBee Encapsulation Protocol, Channel: 25, Length: 77
IEEE 802.15.4 Data, Dst: 0x6663, Src: 0x0000
    Frame Control Field: 0x8861, Frame Type: Data, Acknowledge Request, PAN ID Compression, Destination Addressing Mode: Short/16-bit, Frame Version: IEEE Std 802.15.4-2003, Source Addressing Mode: Short/16-bit
    Sequence Number: 90
    Destination PAN: 0xe8dd
    Destination: 0x6663
    Source: 0x0000
    [Extended Source: Dresden-_ff:ff:01:02:56 (00:21:2e:ff:ff:01:02:56)]
    [Origin: 2]
    Frame Check Sequence (TI CC24xx format): FCS OK
ZigBee Network Layer Command, Dst: 0x6663, Src: 0x0000
    Frame Control Field: 0x1a09, Frame Type: Command, Discover Route: Suppress, Security, Destination, Extended Source Command
    Destination: 0x6663
    Source: 0x0000
    Radius: 10
    Sequence Number: 47
    Destination: Jennic_00:02:83:4c:6c (00:15:8d:00:02:83:4c:6c)
    Extended Source: Dresden-_ff:ff:01:02:56 (00:21:2e:ff:ff:01:02:56)
    ZigBee Security Header
    Command Frame: Route Reply
        Command Identifier: Route Reply (0x02)
        Command Options: 0x30, Extended Responder, Extended Originator
        Route ID: 10
        Originator: 0x6663
        Responder: 0x0000
        Path Cost: 7
        Extended Originator: Jennic_00:02:83:4c:6c (00:15:8d:00:02:83:4c:6c)
        Extended Responder: Dresden-_ff:ff:01:02:56 (00:21:2e:ff:ff:01:02:56)

However, this is sent directly to the controller at MAC level, where the controller is not within reach of the RaspBee. The last successful command from the RaspBee to the controller took three hops at 10:38:50:

Frame 96567: 124 bytes on wire (992 bits), 124 bytes captured (992 bits) on interface 0
Ethernet II, Src: Raspberr_3b:e8:df (b8:27:eb:3b:e8:df), Dst: Apple_ca:3b:53 (a4:5e:60:ca:3b:53)
Internet Protocol Version 4, Src: 192.168.76.81, Dst: 192.168.76.41
User Datagram Protocol, Src Port: 47105, Dst Port: 17754
ZigBee Encapsulation Protocol, Channel: 25, Length: 50
IEEE 802.15.4 Data, Dst: 0xa713, Src: 0x0000
    Frame Control Field: 0x8861, Frame Type: Data, Acknowledge Request, PAN ID Compression, Destination Addressing Mode: Short/16-bit, Frame Version: IEEE Std 802.15.4-2003, Source Addressing Mode: Short/16-bit
    Sequence Number: 174
    Destination PAN: 0xe8dd
    Destination: 0xa713
    Source: 0x0000
    [Extended Source: Dresden-_ff:ff:01:02:56 (00:21:2e:ff:ff:01:02:56)]
    [Origin: 2]
    Frame Check Sequence (TI CC24xx format): FCS OK
ZigBee Network Layer Data, Dst: 0x6663, Src: 0x0000
    Frame Control Field: 0x0248, Frame Type: Data, Discover Route: Enable, Security Data
    Destination: 0x6663
    Source: 0x0000
    Radius: 10
    Sequence Number: 134
    [Extended Source: Dresden-_ff:ff:01:02:56 (00:21:2e:ff:ff:01:02:56)]
    [Origin: 2]
    ZigBee Security Header
ZigBee Application Support Layer Data, Dst Endpt: 1, Src Endpt: 1
    Frame Control Field: Data (0x00)
    Destination Endpoint: 1
    Cluster: On/Off (0x0006)
    Profile: Home Automation (0x0104)
    Source Endpoint: 1
    Counter: 214
ZigBee Cluster Library Frame, Command: Read Attributes, Seq: 45
    Frame Control Field: Profile-wide (0x10)
    Sequence Number: 45
    Command: Read Attributes (0x00)
    Attribute: OnOff (0x0000)

Frame 96569: 124 bytes on wire (992 bits), 124 bytes captured (992 bits) on interface 0
Ethernet II, Src: Raspberr_3b:e8:df (b8:27:eb:3b:e8:df), Dst: Apple_ca:3b:53 (a4:5e:60:ca:3b:53)
Internet Protocol Version 4, Src: 192.168.76.81, Dst: 192.168.76.41
User Datagram Protocol, Src Port: 47105, Dst Port: 17754
ZigBee Encapsulation Protocol, Channel: 25, Length: 50
IEEE 802.15.4 Data, Dst: 0xf1bd, Src: 0xa713
    Frame Control Field: 0x8861, Frame Type: Data, Acknowledge Request, PAN ID Compression, Destination Addressing Mode: Short/16-bit, Frame Version: IEEE Std 802.15.4-2003, Source Addressing Mode: Short/16-bit
    Sequence Number: 240
    Destination PAN: 0xe8dd
    Destination: 0xf1bd
    Source: 0xa713
    [Extended Source: Jennic_00:02:4a:70:18 (00:15:8d:00:02:4a:70:18)]
    [Origin: 109]
    Frame Check Sequence (TI CC24xx format): FCS OK
ZigBee Network Layer Data, Dst: 0x6663, Src: 0x0000
    Frame Control Field: 0x0248, Frame Type: Data, Discover Route: Enable, Security Data
    Destination: 0x6663
    Source: 0x0000
    Radius: 9
    Sequence Number: 134
    [Extended Source: Dresden-_ff:ff:01:02:56 (00:21:2e:ff:ff:01:02:56)]
    [Origin: 2]
    ZigBee Security Header
ZigBee Application Support Layer Data, Dst Endpt: 1, Src Endpt: 1
    Frame Control Field: Data (0x00)
    Destination Endpoint: 1
    Cluster: On/Off (0x0006)
    Profile: Home Automation (0x0104)
    Source Endpoint: 1
    Counter: 214
ZigBee Cluster Library Frame, Command: Read Attributes, Seq: 45
    Frame Control Field: Profile-wide (0x10)
    Sequence Number: 45
    Command: Read Attributes (0x00)
    Attribute: OnOff (0x0000)

Frame 96572: 124 bytes on wire (992 bits), 124 bytes captured (992 bits) on interface 0
Ethernet II, Src: Raspberr_3b:e8:df (b8:27:eb:3b:e8:df), Dst: Apple_ca:3b:53 (a4:5e:60:ca:3b:53)
Internet Protocol Version 4, Src: 192.168.76.81, Dst: 192.168.76.41
User Datagram Protocol, Src Port: 47105, Dst Port: 17754
ZigBee Encapsulation Protocol, Channel: 25, Length: 50
IEEE 802.15.4 Data, Dst: 0x6663, Src: 0xf1bd
    Frame Control Field: 0x8861, Frame Type: Data, Acknowledge Request, PAN ID Compression, Destination Addressing Mode: Short/16-bit, Frame Version: IEEE Std 802.15.4-2003, Source Addressing Mode: Short/16-bit
    Sequence Number: 125
    Destination PAN: 0xe8dd
    Destination: 0x6663
    Source: 0xf1bd
    [Extended Source: PhilipsL_01:10:41:c0:e6 (00:17:88:01:10:41:c0:e6)]
    [Origin: 241]
    Frame Check Sequence (TI CC24xx format): FCS OK
ZigBee Network Layer Data, Dst: 0x6663, Src: 0x0000
    Frame Control Field: 0x0248, Frame Type: Data, Discover Route: Enable, Security Data
    Destination: 0x6663
    Source: 0x0000
    Radius: 8
    Sequence Number: 134
    [Extended Source: Dresden-_ff:ff:01:02:56 (00:21:2e:ff:ff:01:02:56)]
    [Origin: 2]
    ZigBee Security Header
ZigBee Application Support Layer Data, Dst Endpt: 1, Src Endpt: 1
    Frame Control Field: Data (0x00)
    Destination Endpoint: 1
    Cluster: On/Off (0x0006)
    Profile: Home Automation (0x0104)
    Source Endpoint: 1
    Counter: 214
ZigBee Cluster Library Frame, Command: Read Attributes, Seq: 45
    Frame Control Field: Profile-wide (0x10)
    Sequence Number: 45
    Command: Read Attributes (0x00)
    Attribute: OnOff (0x0000)

Here's the corresponding log messages:

$ journalctl -af | grep -i -e 0x6663 -e 0x00158d0002834c6c -e /lights/327
Oct 12 10:38:51 pi2 deCONZ[30176]: 10:38:50:334 APS-DATA.request id: 96, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0006, ep: 0x01 -> 0x01 queue: 8 len: 5 tx.options 0x00
Oct 12 10:38:51 pi2 deCONZ[30176]: 10:38:50:433 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0006, lqi: 255, rssi: -58
Oct 12 10:42:48 pi2 deCONZ[30176]: 10:42:40:052 APS-DATA.request id: 51, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0102, ep: 0x01 -> 0x01 queue: 2 len: 4 tx.options 0x04
Oct 12 10:42:48 pi2 deCONZ[30176]: 10:42:44:159 0x00158D0002834C6C error APSDE-DATA.confirm: 0xA7 on task
ebaauw commented 6 years ago

I'll be damned. Seeing some red nodes (innr PL 110 and Hue LCT003) that don't react to unicast either. I tried to revive them by pressing 0, to no avail. However, the curtain controller magically is reachable again. I cannot find any traffic to or from the controller that would have caused this. I can only imagine that one of its neighbours communicated the route to the RaspBee. That might explain why the issue doesn't appear on my test network: only a few nodes, so the neighbour table gets polled so frequently, that the issue is corrected before detected.

manup commented 6 years ago

Great find, there are two things I'll check in the firmware:

1) What happens when a route request with coordinator as target is received. Not sure if the route is dropped, but what might happen is that the entry from neighbor table is used for routing, it would look just like that.

2) The stack can be configured with a threshold on what it considers a good enough neighbor for direct routing based on link cost from the received NWK Link Status messages. Currently it considers nearly all neighbors as direct routeable, which just might cause the above problem.

I'll cook up a firmware which lowers the above threshold so neighbors should only be considered for routing when signal is stronger.

Note: RasBee and ConBee have a power amplifier and low noise amplifier (LNA) meaning they can see a lot more traffic than usual ZigBee devices like lights and sensors do.

manup commented 6 years ago

The following firmware 0x26270500 has new link cost settings:

The route link cost will filter for more stable routes. The neighbor link cost will cause route establishment when nwk link status link cost is above 1.

https://www.dresden-elektronik.de/rpi/deconz-firmware/deCONZ_Rpi_0x26270500.bin.GCF

ebaauw commented 6 years ago

Thanks. Now running 0x26270500. The curtain controller is reachable, so are my two innr bulbs (see #806). They turned up red pretty soon after startup, both with a direct line to the RaspBee. A while later, that line was removed, while other neighbours of the bulbs were discovered. They turned yellow and are now reachable. I'll check back after running for a couple of hours.

Fingers crossed...

ooii commented 6 years ago

Hi,

I'm wondering if that can be related to the fact that my deConz system becomes slower and less reliable with time. After an upgrade of the system and a restart, (almost) everything works fine. But after few days, it starts being slower (lights react seconds later after being triggered) and less reliable (one of two lights triggered by a sensor are not turned on, etc).

ebaauw commented 6 years ago

Is 0x26270500 based on 26? The curtain controller seems fine, but some lights still turn red (as with 24 - 26), amongst those the two innr bulbs. They do seem to recover spontaneously, though. The REST API sends corresponding web socket notifications:

Oct 12 13:51:49 pi2 dc_eventlog[691]: /lights/251/state: {"reachable":false}
Oct 12 13:51:52 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":false}
Oct 12 13:51:58 pi2 dc_eventlog[691]: /lights/251/state: {"reachable":true}
Oct 12 13:51:58 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":true}
Oct 12 14:17:39 pi2 dc_eventlog[691]: /lights/221/state: {"reachable":false}
Oct 12 14:19:48 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":false}
Oct 12 14:19:50 pi2 dc_eventlog[691]: /lights/221/state: {"reachable":true}
Oct 12 14:20:14 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":true}
Oct 12 14:21:16 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":false}
Oct 12 14:21:22 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":true}
Oct 12 14:32:38 pi2 dc_eventlog[691]: /lights/315/state: {"reachable":false}
Oct 12 14:33:45 pi2 dc_eventlog[691]: /lights/315/state: {"reachable":true}
Oct 12 14:51:49 pi2 dc_eventlog[691]: /lights/315/state: {"reachable":false}
Oct 12 15:03:04 pi2 dc_eventlog[691]: /lights/315/state: {"reachable":true}
Oct 12 15:38:02 pi2 dc_eventlog[691]: /lights/251/state: {"reachable":false}
Oct 12 15:38:49 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":false}
Oct 12 15:45:11 pi2 dc_eventlog[691]: /lights/251/state: {"reachable":true}
Oct 12 15:53:50 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":true}

251 and 261 are the innr bulbs. 221 is a Hue LCT003 extended color GU.10 spot, 315 is a Hue LTW013 color temperature GU.10 spot. Both are in close proximity to other spots of the same type, that don't show issues.

manup commented 6 years ago

Is 0x26270500 based on 26? The curtain controller seems fine, but some lights still turn red (as with 24 - 26), amongst those the two innr bulbs. They do seem to recover spontaneously, though. The REST API sends corresponding web socket notifications:

Yes it's based on 0x26260500, do you also have installed deCONZ core application 2.05.40 or just the compiled plugin with a former deCONZ version? There were some changes about loading nodes from database in core application (changelog comes soon).

My network here still runs without any issues, to proceed I really need to somehow reproduce the issues.

I'll see that I can distribute the devices more (currently just ~60 m²) in order to force more routing. Maybe I can place some in the house stairway :)

When you press the LQI button in deCONZ GUI you can see link quality between nodes, extracted from the neighbor table entries, this may give more insight.

ebaauw commented 6 years ago

do you also have installed deCONZ core application 2.05.40 or just the compiled plugin with a former deCONZ version?

I installed 2.05.40 yesterday, and I'm using the stock REST API plugin.

I'll see that I can distribute the devices more (currently just ~60 m²)

I live in a two-floor apartment that isn't much bigger per floor. If anything, my network is too dense, at least a dozen neighbours per node: screenshot 2018-10-12 at 16 36

ebaauw commented 6 years ago

Network seems stable overnight, no nodes remain red permanently.

Oct 12 15:53:50 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":true}
Oct 12 15:56:56 pi2 dc_eventlog[691]: /lights/235/state: {"reachable":false}
Oct 12 16:01:05 pi2 dc_eventlog[691]: /lights/235/state: {"reachable":true}
Oct 12 17:29:07 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":false}
Oct 12 17:32:54 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":true}
Oct 12 17:46:55 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":false}
Oct 12 17:47:01 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":true}
Oct 12 19:33:12 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":false}
Oct 12 19:35:31 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":true}
Oct 12 21:34:52 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":false}
Oct 12 21:34:56 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":true}
Oct 12 23:36:26 pi2 dc_eventlog[691]: /lights/332/state: {"reachable":false}
Oct 12 23:39:38 pi2 dc_eventlog[691]: /lights/332/state: {"reachable":true}
Oct 13 01:07:13 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":false}
Oct 13 01:09:12 pi2 dc_eventlog[691]: /lights/261/state: {"reachable":true}
Oct 13 07:57:24 pi2 dc_eventlog[691]: /lights/332/state: {"reachable":false}
Oct 13 08:09:59 pi2 dc_eventlog[691]: /lights/332/state: {"reachable":true}
Oct 13 09:00:22 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":false}
Oct 13 09:00:45 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":true}
Oct 13 09:43:46 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":false}
Oct 13 09:46:37 pi2 dc_eventlog[691]: /lights/327/state: {"reachable":true}

327 is the lumi.curtain; 332 is an innr plug; both are on the outside wall of my apartment. 261 is one of the innr bulbs, in the middle of my apartment.

manup commented 6 years ago

Very interesting, so the parameters seem to have a positive effect. Relaxing the max route link cost filter a bit more (from 3 to 4) might help with the remaining issues.

ebaauw commented 6 years ago

I'll be happy to try that. Will you be creating a new firmware version for that?

ooii commented 6 years ago

Hi,

When looking to @ebaauw's network, I figure out that mine is far less denser than his. My gateway is at the basement of our house and I have devices at all levels (basement, ground, 1st and 2nd floor). I observe that I have very few 2-hops links and that many of my devices don't have any link with the gateway. Despite this observation, I can control my lights with my sensors and switches even if the system is not reliable and requires, frequently, several button presses to respond. Do you think the connectivity of my network as you can see it can be the reason of my low-reliable system? If yes, can I make it denser? For instance, should I move the gateway from basement to ground or first floor to make it more central? Thank you for your help.

ebaauw commented 6 years ago

Did you take this screenshot shortly after starting deCONZ? It looks like deCONZ hasn't yet discovered (and drawn) all the connections. In fact, it mostly shows direct connections from the RaspBee and a lot of unconnected routers.

ooii commented 6 years ago

Yes, shortly after restarting deCONZ. I'll send a feedback later when I'm able to start the gui while the service is running for long.

ebaauw commented 6 years ago

Relaxing the max route link cost filter a bit more (from 3 to 4) might help with the remaining issues.

@manup are you still looking into this?

I had a very weird situation this morning, where the ZDP 0x0005 command from deCONZ to the curtain controller timed out. I think this is the get endpoint command? After that, deCONZ no longer updated the /lights resource, even if I explicitly read the Window Covering attributes. From the deCONZ log, it did receive the responses, and the deCONZ GUI is updated. Also, attribute reports were received, but no ZCL attribute report message, and the GUI wasn't updated. Interestingly, the reports for the 0x000D cluster were recognised, but these are handled from the /sensors logic.

I restarted deCONZ, reset the RaspBee, even reverted to .40, all to no avail. I power cycled the controller pressed 0 and L from the GUI and things are normal again now. The controller still has the same NWK address.

manup commented 6 years ago

@manup are you still looking into this?

Yes this is in fact my weekend project :)

I've done many tests and sniffer samples with various end devices and routers:

Turns out across vendors this is very differently handled.

I'll but up the results in the Wiki, it's very interesting and should help to get rid of many problems which are currently haunting around.

.42 will be out later today with the 0x26280500 firmware:

https://www.dresden-elektronik.de/rpi/deconz-firmware/deCONZ_Rpi_0x26280500.bin.GCF

The last one is a real bummer and could cause the firmware to block the queue for a long time especially the longer deCONZ runs. There could be active APS requests in the firmware waiting until 93 minutes until timeout. While the deCONZ application has released the request (falsely) already.

Since there can be only up to 10 requests active in the firmware this can pile up rather quickly when multiple requests are send to non responding end devices.

The new firmware won't block a request for more than 7680 milliseconds (which is what the standard suggests) and it is what also IKEA, Innr, Philips and other routers do. OSRAM seems to hold a message for up to 20 seconds.

ooii commented 6 years ago

Hi @manup,

The last one is a real bummer and could cause the firmware to block the queue for a long time especially the longer deCONZ runs.

This seems related to what I said in my previous message https://github.com/dresden-elektronik/deconz-rest-plugin/issues/849#issuecomment-429310908 no?

manup commented 6 years ago

This seems related to what I said in my previous message #849 (comment) no?

Absolutely, lets see how it behaves with new version running for some time.

ooii commented 6 years ago

I'll wait for .42

One more question related to this issue and another one https://github.com/dresden-elektronik/deconz-rest-plugin/issues/867 I raised and that did not receive answer. Where is stored nodes' neighbourhood and links quality? I'd like to read this data and represent the network in a web interface.

ebaauw commented 6 years ago

Hm, upgraded to 0x26280500 (running 2.05.41 with included REST API plugin). Looked like deCONZ left and rejoined the network shortly after starting:

Oct 21 17:21:00 pi2 deCONZ[11839]: 17:20:59:622 0x00158D0000CDD7F7 error APSDE-DATA.confirm: 0xA7 on task
Oct 21 17:21:00 pi2 deCONZ[11839]: 17:20:59:810 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Oct 21 17:21:00 pi2 deCONZ[11839]: 17:20:59:810 device state timeout ignored in state 2
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:241 ??o ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ???o    ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o
Oct 21 17:21:05 pi2 deCONZ[11839]:  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!???9?HF?BJ??????o  ??s!!??
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:248 RaspBee Bootloader premium
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:251 Vers. 1.02
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:256 build 2013/08/01
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:305 APS-DATA.request id: 120, addrmode: 0x03, addr: 0x000d6f000be643b8, profile: 0x0104, cluster: 0x0004, ep: 0x01 -> 0x01 queue: 0 len: 4 tx.options 0x00
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:341 aps request id: 120 prf: 0x0104 cl: 0x0004 timeout (confirmed: 0) to 0x000D6F000BE643B8 (0x119A)
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:421 aps request id: 120 failed, erase from queue
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:421 emit artificial APSDE-DATA.confirm id: 120
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:421 0x000D6F000BE643B8 error APSDE-DATA.confirm: 0xA7 on task
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:448 Error: invalid command
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:00:756 STARTING APP
Oct 21 17:21:05 pi2 deCONZ[11839]: PROTO: CRC error
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:01:244 APS-DATA.request id: 79, status: 0x06 giveup
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:01:244 APS-DATA.request id: 79, failed-status: APP_ENONET (0x06)
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:01:423 Device firmware version 0x26280500
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:02:879 DEV config changed event
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:02:897 unlocked max nodes: 200
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:02:941 APS-DATA.request id: 139, addrmode: 0x02, addr: 0x3938, profile: 0x0000, cluster: 0x0004, ep: 0x00 -> 0x00 queue: 0 len: 4 tx.options 0x04
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:080 Device protocol version: 0x0108
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:211 Current channel 25
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:241 CTRL got nwk update id 9
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:252 CTRL ANT_CTRL 0x03
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:263 APS-DATA.request id: 141, addrmode: 0x02, addr: 0xe8df, profile: 0x0000, cluster: 0x0004, ep: 0x00 -> 0x00 queue: 1 len: 4 tx.options 0x04
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:475 Device protocol version: 0x0108
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:559 APS-DATA.request id: 143, addrmode: 0x03, addr: 0x0017880100d767dc, profile: 0x0104, cluster: 0x0004, ep: 0x01 -> 0x0B queue: 2 len: 4 tx.options 0x00
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:611 Current channel 25
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:654 CTRL got nwk update id 9
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:785 CTRL ANT_CTRL 0x03
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:865 Device protocol version: 0x0108
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:03:996 Current channel 25
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:026 CTRL got nwk update id 9
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:036 CTRL ANT_CTRL 0x03
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:116 Device protocol version: 0x0108
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:245 Current channel 25
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:275 CTRL got nwk update id 9
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:285 CTRL ANT_CTRL 0x03
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:309 APS-DATA.request id: 147, addrmode: 0x03, addr: 0x00158d00007e2feb, profile: 0x0104, cluster: 0x0004, ep: 0x01 -> 0x01 queue: 3 len: 4 tx.options 0x00
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:635 APS-DATA.confirm id: 109, status: 0x00 SUCCESS
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:04:635 APS-DATA.confirm id: 109, status: 0x00, match: 0
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:05:003 0x0017880100D767DC error APSDE-DATA.confirm: 0xD0 on task
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:05:003 APS-DATA.confirm id: 143, status: 0xD0
Oct 21 17:21:05 pi2 deCONZ[11839]: 17:21:05:017 APS-DATA.confirm id: 147, status: 0x00 SUCCESS
manup commented 6 years ago

Jup that's fine it only starts the network after powerup, firmware update is like a powercycle :)

ebaauw commented 6 years ago

I stopped deCONZ, did a manual firmware update with GCFFlasher and restarted deCONZ. The GUI already displayed the network, and was busy drawing the connections when it left and rejoined the network.

ooii commented 6 years ago

Updated to .42. Seemed to work at first then strange behavior; dc_eventlogshows activity but I'm unable to find the gateway through the web interface (Please wait until the search for gateways has finished) and homebridge-huecomplains with a RaspBee/ConBee not yet initialised - wait 1 minutemessage. I'm however able to use my sensors and switches.

ebaauw commented 6 years ago

Running v2.05.42 with 0x26280500 since yesterday evening. Network seems stable enough, but deCONZ still loses reachability to lights:

Oct 21 20:22:13 pi2 dc_eventlog[1711]: /lights/251/state: {"reachable":false}
Oct 21 20:27:57 pi2 dc_eventlog[1711]: /lights/251/state: {"reachable":true}
Oct 21 20:35:23 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":false}
Oct 21 20:35:50 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":true}
Oct 21 21:32:04 pi2 dc_eventlog[1711]: /lights/332/state: {"reachable":false}
Oct 21 21:35:22 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":false}
Oct 21 21:35:50 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":true}
Oct 21 21:41:01 pi2 dc_eventlog[1711]: /lights/251/state: {"reachable":false}
Oct 21 21:48:05 pi2 dc_eventlog[1711]: /lights/332/state: {"reachable":true}
Oct 21 21:48:55 pi2 dc_eventlog[1711]: /lights/251/state: {"reachable":true}
Oct 21 21:55:18 pi2 dc_eventlog[1711]: /lights/332/state: {"reachable":false}
Oct 21 21:58:06 pi2 dc_eventlog[1711]: /lights/332/state: {"reachable":true}
Oct 21 22:04:42 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 21 22:05:07 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":false}
Oct 21 22:05:50 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":true}
Oct 21 22:06:08 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 21 22:07:32 pi2 dc_eventlog[1711]: /lights/325/state: {"reachable":true}
Oct 21 22:07:32 pi2 dc_eventlog[1711]: /lights/326/state: {"reachable":true}
Oct 21 22:15:55 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 21 22:24:03 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 21 22:35:25 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":false}
Oct 21 22:35:50 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":true}
Oct 21 23:05:45 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":false}
Oct 21 23:05:50 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":true}
Oct 21 23:08:14 pi2 dc_eventlog[1711]: /lights/327/state: {"reachable":false}
Oct 21 23:11:50 pi2 dc_eventlog[1711]: /lights/327/state: {"reachable":true}
Oct 21 23:16:33 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 21 23:22:39 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 21 23:35:19 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 21 23:35:20 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":false}
Oct 21 23:35:50 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":true}
Oct 21 23:42:20 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 21 23:57:18 pi2 dc_eventlog[1711]: /lights/332/state: {"reachable":false}
Oct 22 00:21:31 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 00:22:37 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 00:42:46 pi2 dc_eventlog[1711]: /lights/332/state: {"reachable":true}
Oct 22 00:54:01 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 01:05:35 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":false}
Oct 22 01:05:51 pi2 dc_eventlog[1711]: /lights/101/state: {"reachable":true}
Oct 22 01:05:53 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 02:33:58 pi2 dc_eventlog[1711]: /lights/332/state: {"reachable":false}
Oct 22 02:34:35 pi2 dc_eventlog[1711]: /lights/332/state: {"reachable":true}
Oct 22 03:40:05 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 03:41:08 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 04:02:05 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 04:25:13 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 04:40:17 pi2 dc_eventlog[1711]: /lights/341/state: {"reachable":true}
Oct 22 04:42:27 pi2 dc_eventlog[1711]: /lights/341/state: {"reachable":true}
Oct 22 04:49:46 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 05:02:01 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 05:15:01 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 05:17:54 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 06:12:03 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 06:12:46 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 07:40:30 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":false}
Oct 22 07:54:58 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":true}
Oct 22 08:41:13 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 08:44:52 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 09:23:55 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 09:28:11 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 10:35:28 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 10:38:08 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 11:46:19 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 11:51:44 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 11:57:52 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 11:59:10 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 12:07:16 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 12:10:11 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 12:20:36 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 12:42:58 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 14:02:01 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":false}
Oct 22 14:06:25 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 14:07:08 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 14:07:08 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":true}
Oct 22 14:14:22 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":false}
Oct 22 14:20:47 pi2 dc_eventlog[1711]: /lights/221/state: {"reachable":true}
Oct 22 14:34:31 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":false}
Oct 22 14:36:11 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":true}
Oct 22 15:07:26 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 15:12:28 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 15:15:22 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 15:16:49 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 15:51:28 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 16:55:00 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 17:00:05 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":false}
Oct 22 17:15:15 pi2 dc_eventlog[1711]: /lights/229/state: {"reachable":true}
Oct 22 17:35:48 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":false}
Oct 22 17:36:10 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":true}
Oct 22 17:50:04 pi2 dc_eventlog[1711]: /lights/261/state: {"reachable":true}
manup commented 6 years ago

My innr is now reliably not working since I took some routers from power for better testing :)

Some discoveries

Also out of interest I compared how Ikea and a Hue Lux see and report the innr light in link status messages.

IKEA E27 Firmware 1.2.214 0x7592 (Floor)

Link cost entry innr 0x5b8d Incoming cost 7 Outgoing cost 0

Hue Lux E27 20140324 0x35cd (Bathroom)

Link cost entry innr 0x5b8d Incoming cost 2 Outgoing cost 7

And now the interesting part, in the next sample I just switched the exact position of Ikea with Hue Lux.

IKEA 0x7592 (Bathroom)

Link cost entry innr 0x5b8d Incoming cost 7 Outgoing cost 0

Hue Lux E27 0x35cd (Floor)

Link cost entry innr 0x5b8d Incoming cost 1 Outgoing cost 7

Either Ikea or Philips got the incoming/outgoing cost completely wrong (I need to read more on this in the spec to find out). Since all routing and mesh functionality depends on this it's pretty bad.

The Lux firmware is pretty old I'll check if there is some new available via Philips Hue bridge.

manup commented 6 years ago

Updated the Hue Lux

Date Code SW Build ID
Before 20140324 5.17.1.12040
After 20170908 5.105.0.21169

Same results.

I've also moved my Osram Smart+ plug 5 meters next to the innr, the network got stable after a few seconds and meshing works as expected with the plug as repeater to reach the innr.

I'm using a new firmware 0x26290500 with disabled route optimizations, like building routes from link status messages. Also the deCONZ core is changed to force route requests more quickly and don't use NWK address request broadcasts to find routers.

ebaauw commented 6 years ago

My innr is now reliably not working

LOL

But seriously: thanks for looking into this. The lights in between my innr bulbs and the RaspBee would likely be Philips dimmable lights.

{
  "etag": "5a470edfebc57c3c5c7602961b51380b",
  "hascolor": false,
  "manufacturername": "Philips",
  "modelid": "LWB006",
  "name": "Hallway 1",
  "state": {
    "alert": "none",
    "bri": 254,
    "on": false,
    "reachable": true
  },
  "swversion": "5.105.0.21169",
  "type": "Dimmable light",
  "uniqueid": "00:17:88:01:10:36:ce:87-0b"
}
ooii commented 6 years ago

@manup would you please look to https://github.com/dresden-elektronik/deconz-rest-plugin/issues/896, I'm stuck with this problem and can't fix it. I'm now using my old electric switches :'(

ebaauw commented 6 years ago

Now running 2.05.43 with 0x262b0500. After running for 30 minutes, the network seems less dense - fewer lines in the GUI. I had to power cycle one of my IKEA Trådfri bulbs and on of my innr UC 110 lights, before they could be reached by unicast. Interestingly, the innr node did only blink blue (not red), but no response was received.

screenshot 2018-10-26 at 12 53

manup commented 6 years ago

the innr node did only blink blue (not red), but no response was received.

Which one is the innr node?

The routing issues with my innr bulb were solved (in the test network) by using a router in between.

Blinking blue could also mean that the request was send (aps confirm success) to the next hop which might be the innr light itself.

Do you have APS Acks enabled in deCONZ network settings? The mgmt lqi requests to query the neighbor tables will use this.

There are still open issues in regard to route maintenance which I hope to figure out in the next firmware releases.

ebaauw commented 6 years ago

Which one is the innr node?

Kitchen Left. This is an under cabinet light, UC 110 - not one of the bulbs. I haven't had issues with these before (nor with the PL 110 which has the same controller box).

Do you have APS Acks enabled in deCONZ network settings?

Yes.

There are still open issues in regard to route maintenance which I hope to figure out in the next firmware releases.

Yeah, I (temporarily) lost two routers (the innr PL 110 and the Xiaomi curtain) and one Hue motion sensor. Also, I seem to have had some delays and failures in scene activation. Not exactly sure what's going on.

Krocko commented 6 years ago

With the new version i have problems too with a hue motion sensor. The LED is blinking red on almost any motion. After a while the Sensor don‘t work anymore.

manup commented 6 years ago

:( what is this sorcery

@ebaauw can you please sniff the traffic for the motion sensor, usually the gateway should send a zcl default response to every sensor report to keep the sensor happy.

In my home network it runs fine as usual. I'll place a Philips sensor in the mixed network at work on Monday, see if I can reproduce the issue.

ebaauw commented 6 years ago

I’ll try next time one of them is lost. I revived it by briefly pressing the reset button, after opening the network. The attribute report settings where re-established in full rather quickly; at least there seems to be an improvement on this part.

manup commented 6 years ago

Firmware 0x262d0500 addresses the following issues:

https://www.dresden-elektronik.de/rpi/deconz-firmware/deCONZ_Rpi_0x262d0500.bin.GCF

ebaauw commented 6 years ago

Upgraded to 0x262d0500. Looking good so far.

manup commented 6 years ago

Upgraded to 0x262d0500. Looking good so far.

Did it survive the night?

In one of my test networks all green lines disappeared albeit all nodes were working, seems to be a glitch in core Mgtm_Lqi_req query but not related to firmware, after deCONZ restart (firmware kept running) all lines came back.

ebaauw commented 6 years ago

Did it survive the night?

Mostly. Green lines show, no unreachable lights, all Hue motion sensors continue to send reports. I did lose my curtain controller, twice now. The special attribute reports arrive, but commands sent to the controller time out.

$ journalctl -a | grep -i -e 0x00158d0002834c6c -e 0x3e17 -e /lights/327 -e curtains
Oct 28 16:01:32 pi2 deCONZ[32670]: 16:01:31:517 APS-DATA.request id: 104, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 3 len: 5 tx.options 0x04
Oct 28 16:01:32 pi2 deCONZ[32670]: 16:01:31:699 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 255, rssi: -51
Oct 28 16:04:00 pi2 deCONZ[32670]: 16:04:00:560 APS-DATA.request id: 2, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0004, ep: 0x01 -> 0x01 queue: 3 len: 4 tx.options 0x00
Oct 28 16:04:07 pi2 deCONZ[32670]: 16:04:00:677 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0004, lqi: 143, rssi: -73
Oct 28 16:04:07 pi2 deCONZ[32670]: 16:04:00:677 verified group capacity: 7 and group count: 1 of LightNode 0x00158d0002834c6c
Oct 28 16:04:07 pi2 deCONZ[32670]: 16:04:00:678 0x00158d0002834c6c found group 0x0000
Oct 28 16:05:02 pi2 deCONZ[32670]: 16:05:00:173 APS-DATA.request id: 127, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:05:02 pi2 deCONZ[32670]: 16:05:00:353 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 255, rssi: -49
Oct 28 16:06:16 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:06:16 pi2 dc_eventlog[22469]: /lights/327/state: {"bri":0}
Oct 28 16:06:16 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:06:16 pi2 dc_eventlog[22469]: /lights/327/state: {"on":false}
Oct 28 16:06:18 pi2 deCONZ[32670]: 16:06:16:017 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 255, rssi: -49
Oct 28 16:06:18 pi2 deCONZ[32670]: 16:06:16:017 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 28 16:06:18 pi2 deCONZ[32670]: 16:06:16:018 0x00158D0002834C6C extract Xiaomi special
Oct 28 16:08:25 pi2 deCONZ[32670]: 16:08:24:942 APS-DATA.request id: 122, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:09:09 pi2 deCONZ[32670]: 16:09:07:757 APS-DATA.request id: 120, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 4 len: 5 tx.options 0x04
Oct 28 16:12:34 pi2 deCONZ[32670]: 16:12:27:669 APS-DATA.request id: 114, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:13:28 pi2 deCONZ[32670]: 16:13:23:517 APS-DATA.request id: 199, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:14:46 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:14:46 pi2 dc_eventlog[22469]: /lights/327/state: {"bri":0}
Oct 28 16:14:46 pi2 dc_eventlog[22469]: /lights/327/state: {"on":false}
Oct 28 16:14:47 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:14:59 pi2 deCONZ[32670]: 16:14:46:990 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 255, rssi: -51
Oct 28 16:14:59 pi2 deCONZ[32670]: 16:14:46:990 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 28 16:14:59 pi2 deCONZ[32670]: 16:14:46:990 0x00158D0002834C6C extract Xiaomi special
Oct 28 16:16:55 pi2 deCONZ[32670]: 16:16:50:110 APS-DATA.request id: 10, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 5 len: 5 tx.options 0x04
Oct 28 16:17:40 pi2 deCONZ[32670]: 16:17:39:469 APS-DATA.request id: 36, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:19:15 pi2 deCONZ[32670]: 16:19:08:582 APS-DATA.request id: 50, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 4 len: 2 tx.options 0x04
Oct 28 16:21:05 pi2 deCONZ[32670]: 16:20:55:117 APS-DATA.request id: 243, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:21:57 pi2 deCONZ[32670]: 16:21:53:469 APS-DATA.request id: 92, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 3 len: 5 tx.options 0x04
Oct 28 16:24:45 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:24:45 pi2 dc_eventlog[22469]: /lights/327/state: {"bri":0}
Oct 28 16:24:45 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:24:46 pi2 dc_eventlog[22469]: /lights/327/state: {"on":false}
Oct 28 16:24:49 pi2 deCONZ[32670]: 16:24:45:991 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 255, rssi: -52
Oct 28 16:24:49 pi2 deCONZ[32670]: 16:24:45:991 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 28 16:24:49 pi2 deCONZ[32670]: 16:24:45:991 0x00158D0002834C6C extract Xiaomi special
Oct 28 16:25:16 pi2 deCONZ[32670]: 16:25:13:621 APS-DATA.request id: 41, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 4 len: 5 tx.options 0x04
Oct 28 16:26:02 pi2 deCONZ[32670]: 16:26:01:550 APS-DATA.request id: 70, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:29:34 pi2 deCONZ[32670]: 16:29:30:326 APS-DATA.request id: 119, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:29:34 pi2 deCONZ[32670]: 16:29:32:018 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 191, rssi: -67
Oct 28 16:32:42 pi2 deCONZ[32670]: 16:32:42:421 APS-DATA.request id: 55, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:32:42 pi2 deCONZ[32670]: 16:32:42:597 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 223, rssi: -63
Oct 28 16:33:53 pi2 dc_eventlog[22469]: /lights/327/state: {"bri":0}
Oct 28 16:33:53 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:33:53 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:33:53 pi2 dc_eventlog[22469]: /lights/327/state: {"on":false}
Oct 28 16:33:56 pi2 deCONZ[32670]: 16:33:53:975 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 143, rssi: -73
Oct 28 16:33:56 pi2 deCONZ[32670]: 16:33:53:975 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 28 16:33:56 pi2 deCONZ[32670]: 16:33:53:975 0x00158D0002834C6C extract Xiaomi special
Oct 28 16:34:10 pi2 deCONZ[32670]: 16:34:03:372 APS-DATA.request id: 36, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0004, ep: 0x01 -> 0x01 queue: 2 len: 4 tx.options 0x00
Oct 28 16:34:10 pi2 deCONZ[32670]: 16:34:03:506 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0004, lqi: 143, rssi: -73
Oct 28 16:34:10 pi2 deCONZ[32670]: 16:34:03:506 verified group capacity: 7 and group count: 1 of LightNode 0x00158d0002834c6c
Oct 28 16:34:10 pi2 deCONZ[32670]: 16:34:03:506 0x00158d0002834c6c found group 0x0000
Oct 28 16:36:13 pi2 deCONZ[32670]: 16:36:11:469 APS-DATA.request id: 59, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 3 len: 5 tx.options 0x04
Oct 28 16:36:13 pi2 deCONZ[32670]: 16:36:11:664 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 223, rssi: -63
Oct 28 16:38:06 pi2 deCONZ[32670]: 16:38:02:811 remove outdated neighbor 0x3E17
Oct 28 16:39:24 pi2 deCONZ[32670]: 16:39:22:069 APS-DATA.request id: 210, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:39:24 pi2 deCONZ[32670]: 16:39:22:378 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 255, rssi: -51
Oct 28 16:42:37 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:42:37 pi2 dc_eventlog[22469]: /lights/327/state: {"bri":0}
Oct 28 16:42:37 pi2 dc_eventlog[22469]: /lights/327/state: {"on":false}
Oct 28 16:42:37 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:42:43 pi2 deCONZ[32670]: 16:42:37:010 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 255, rssi: -49
Oct 28 16:42:43 pi2 deCONZ[32670]: 16:42:37:010 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 28 16:42:43 pi2 deCONZ[32670]: 16:42:37:010 0x00158D0002834C6C extract Xiaomi special
Oct 28 16:42:56 pi2 deCONZ[32670]: 16:42:52:149 APS-DATA.request id: 221, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:42:56 pi2 deCONZ[32670]: 16:42:52:568 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 255, rssi: -48
Oct 28 16:46:23 pi2 deCONZ[32670]: 16:46:22:941 APS-DATA.request id: 19, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 4 len: 5 tx.options 0x04
Oct 28 16:46:31 pi2 deCONZ[32670]: 16:46:23:125 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 191, rssi: -67
Oct 28 16:49:57 pi2 deCONZ[32670]: 16:49:51:501 APS-DATA.request id: 9, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:49:57 pi2 deCONZ[32670]: 16:49:53:261 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 191, rssi: -67
Oct 28 16:52:07 pi2 dc_eventlog[22469]: /lights/327/state: {"bri":0}
Oct 28 16:52:07 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:52:07 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 16:52:07 pi2 dc_eventlog[22469]: /lights/327/state: {"on":false}
Oct 28 16:52:15 pi2 deCONZ[32670]: 16:52:07:981 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 247, rssi: -60
Oct 28 16:52:15 pi2 deCONZ[32670]: 16:52:07:981 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 28 16:52:15 pi2 deCONZ[32670]: 16:52:07:981 0x00158D0002834C6C extract Xiaomi special
Oct 28 16:53:20 pi2 deCONZ[32670]: 16:53:18:341 APS-DATA.request id: 246, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:53:20 pi2 deCONZ[32670]: 16:53:18:543 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 191, rssi: -67
Oct 28 16:56:45 pi2 deCONZ[32670]: 16:56:36:757 APS-DATA.request id: 184, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 16:57:43 pi2 deCONZ[32670]: 16:57:31:726 APS-DATA.request id: 12, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 17:00:49 pi2 dc_eventlog[22469]: /lights/327/state: {"bri":0}
Oct 28 17:00:49 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 17:00:49 pi2 dc_eventlog[22469]: /lights/327/state: {"on":false}
Oct 28 17:00:57 pi2 deCONZ[32670]: 17:00:49:050 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 191, rssi: -67
Oct 28 17:00:57 pi2 deCONZ[32670]: 17:00:49:051 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 28 17:00:57 pi2 deCONZ[32670]: 17:00:49:051 0x00158D0002834C6C extract Xiaomi special
Oct 28 17:00:57 pi2 deCONZ[32670]: 17:00:55:654 APS-DATA.request id: 26, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 17:01:58 pi2 deCONZ[32670]: 17:01:51:869 APS-DATA.request id: 125, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 17:02:26 pi2 deCONZ[32670]: 17:02:22:809 remove outdated neighbor 0x3E17
Oct 28 17:02:43 pi2 deCONZ[32670]: 17:02:42:809 remove outdated neighbor 0x3E17
Oct 28 17:04:11 pi2 deCONZ[32670]: 17:04:04:561 APS-DATA.request id: 156, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0004, ep: 0x01 -> 0x01 queue: 1 len: 4 tx.options 0x00
Oct 28 17:04:18 pi2 deCONZ[32670]: 17:04:15:636 0x00158D0002834C6C error APSDE-DATA.confirm: 0xA7 on task
Oct 28 17:05:23 pi2 deCONZ[32670]: 17:05:20:141 APS-DATA.request id: 112, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 3 len: 5 tx.options 0x04
Oct 28 17:06:14 pi2 deCONZ[32670]: 17:06:07:749 APS-DATA.request id: 167, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 17:07:07 pi2 deCONZ[32670]: 17:07:07:096 APS-DATA.request id: 35, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 3 len: 5 tx.options 0x04
Oct 28 17:07:07 pi2 deCONZ[32670]: 17:07:07:096 APS-DATA.request id: 36, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 4 len: 11 tx.options 0x04
Oct 28 17:07:14 pi2 deCONZ[32670]: 17:07:07:096 APS-DATA.request id: 37, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 5 len: 7 tx.options 0x04
Oct 28 17:07:14 pi2 deCONZ[32670]: 17:07:13:602 APS-DATA.request id: 77, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 6 len: 5 tx.options 0x04
Oct 28 17:07:14 pi2 deCONZ[32670]: 17:07:13:602 APS-DATA.request id: 78, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 7 len: 11 tx.options 0x04
Oct 28 17:07:14 pi2 deCONZ[32670]: 17:07:13:603 APS-DATA.request id: 79, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 8 len: 7 tx.options 0x04
Oct 28 17:07:19 pi2 deCONZ[32670]: 17:07:18:595 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 48 s
Oct 28 17:07:19 pi2 deCONZ[32670]: 17:07:18:634 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 48 s
Oct 28 17:07:19 pi2 deCONZ[32670]: 17:07:19:027 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 48 s
Oct 28 17:07:28 pi2 deCONZ[32670]: 17:07:25:087 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 54 s
Oct 28 17:07:28 pi2 deCONZ[32670]: 17:07:25:441 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 55 s
Oct 28 17:07:28 pi2 deCONZ[32670]: 17:07:25:727 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 55 s
Oct 28 17:07:51 pi2 deCONZ[32670]: 17:07:44:891 APS-DATA.request id: 48, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 0 len: 5 tx.options 0x04
Oct 28 17:07:55 pi2 dc_eventlog[22469]: /lights/327/state: {"reachable":false}
Oct 28 17:07:55 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 17:07:55 pi2 homebridge[3807]: [Hue] Bedroom Curtains: light reachable changed from true to false
Oct 28 17:07:55 pi2 homebridge[3807]: [Hue] Bedroom Curtains: set homekit status fault from 0 to 1
Oct 28 17:07:58 pi2 deCONZ[32670]: 17:07:55:547 0x3E17 seems to be a zombie recv errors 11
Oct 28 17:07:58 pi2 deCONZ[32670]: 17:07:55:548 LightNode removed 0x00158d0002834c6c
Oct 28 17:07:58 pi2 deCONZ[32670]: 17:07:55:561 Node zombie state changed 0x00158d0002834c6c
Oct 28 17:08:00 pi2 dc_eventlog[22469]: /lights/327/state: {"reachable":true}
Oct 28 17:08:00 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 17:08:00 pi2 homebridge[3807]: [Hue] Bedroom Curtains: light reachable changed from false to true
Oct 28 17:08:00 pi2 homebridge[3807]: [Hue] Bedroom Curtains: set homekit status fault from 1 to 0
Oct 28 17:08:14 pi2 deCONZ[32670]: 17:08:00:270 send NWK_Addr_req to node  0x00158D0002834C6C
Oct 28 17:08:14 pi2 deCONZ[32670]: 17:08:00:849 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8000, lqi: 231, rssi: -62
Oct 28 17:08:14 pi2 deCONZ[32670]: 17:08:00:849 LightNode 327: Bedroom Curtains updated
Oct 28 17:08:14 pi2 deCONZ[32670]: 17:08:05:259 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8000, lqi: 239, rssi: -61
Oct 28 17:08:14 pi2 deCONZ[32670]: 17:08:12:439 APS-DATA.request id: 204, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 3 len: 5 tx.options 0x04
Oct 28 17:08:14 pi2 deCONZ[32670]: 17:08:12:439 APS-DATA.request id: 205, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 4 len: 11 tx.options 0x04
Oct 28 17:08:14 pi2 deCONZ[32670]: 17:08:12:440 APS-DATA.request id: 206, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 5 len: 7 tx.options 0x04
Oct 28 17:08:25 pi2 deCONZ[32670]: 17:08:20:282 APS-DATA.request id: 5, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 6 len: 5 tx.options 0x04
Oct 28 17:08:25 pi2 deCONZ[32670]: 17:08:20:282 APS-DATA.request id: 6, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 7 len: 11 tx.options 0x04
Oct 28 17:08:25 pi2 deCONZ[32670]: 17:08:20:283 APS-DATA.request id: 7, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x000D, ep: 0x01 -> 0x01 queue: 8 len: 7 tx.options 0x04
Oct 28 17:08:25 pi2 deCONZ[32670]: 17:08:22:562 APS-DATA.request id: 19, addrmode: 0x03, addr: 0x00158d0002834c6c, profile: 0x0104, cluster: 0x0004, ep: 0x01 -> 0x01 queue: 9 len: 4 tx.options 0x00
Oct 28 17:08:35 pi2 deCONZ[32670]: 17:08:32:618 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 122 s
Oct 28 17:09:03 pi2 deCONZ[32670]: 17:09:00:021 aps request id: 138 prf: 0x0000 cl: 0x0000 timeout (confirmed: 1) to 0x00158D0002834C6C (0xFFFD)
Oct 28 17:10:01 pi2 dc_eventlog[22469]: /lights/327/state: {"bri":0}
Oct 28 17:10:01 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 17:10:01 pi2 dc_eventlog[22469]: /lights/327/state: {"on":false}
Oct 28 17:10:01 pi2 homebridge[3807]: [Hue] Bedroom Curtains: state changed event
Oct 28 17:10:06 pi2 deCONZ[32670]: 17:10:01:073 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0000, lqi: 215, rssi: -64
Oct 28 17:10:06 pi2 deCONZ[32670]: 17:10:01:074 ZCL attribute report 0x00158D0002834C6C for cluster 0x0000, ep 0x01
Oct 28 17:10:06 pi2 deCONZ[32670]: 17:10:01:074 0x00158D0002834C6C extract Xiaomi special
Oct 28 17:10:14 pi2 deCONZ[32670]: 17:10:06:201 APS-DATA.request id: 175, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 17:10:14 pi2 deCONZ[32670]: 17:10:06:475 APS-DATA.indication srcAddr: 0x00158d0002834c6c, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 207, rssi: -65
Oct 28 17:13:42 pi2 deCONZ[32670]: 17:13:38:109 APS-DATA.request id: 215, addrmode: 0x02, addr: 0x3e17, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 2 len: 5 tx.options 0x04
Oct 28 17:13:43 pi2 deCONZ[32670]: 17:13:43:674 APS-DATA.request id: 4, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 1 len: 11 tx.options 0x04
Oct 28 17:13:43 pi2 deCONZ[32670]: 17:13:43:674 APS-DATA.request id: 5, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 2 len: 5 tx.options 0x04
Oct 28 17:13:43 pi2 deCONZ[32670]: 17:13:43:674 APS-DATA.request id: 6, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 3 len: 5 tx.options 0x04
Oct 28 17:13:43 pi2 deCONZ[32670]: 17:13:43:674 APS-DATA.request id: 7, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 4 len: 5 tx.options 0x04
Oct 28 17:13:49 pi2 deCONZ[32670]: 17:13:43:675 APS-DATA.request id: 8, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 5 len: 5 tx.options 0x04
Oct 28 17:13:49 pi2 deCONZ[32670]: 17:13:43:675 APS-DATA.request id: 9, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 6 len: 7 tx.options 0x04
Oct 28 17:13:49 pi2 deCONZ[32670]: 17:13:43:675 APS-DATA.request id: 10, addrmode: 0x02, addr: 0x3e17, profile: 0x0104, cluster: 0x0000, ep: 0x01 -> 0x01 queue: 7 len: 9 tx.options 0x04
Oct 28 17:13:57 pi2 deCONZ[32670]: 17:13:57:118 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 246 s
Oct 28 17:13:57 pi2 deCONZ[32670]: 17:13:57:479 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 247 s
Oct 28 17:14:04 pi2 deCONZ[32670]: 17:13:58:039 max transmit errors for node 0x00158D0002834C6C, last seen by neighbors 247 s
ebaauw commented 6 years ago

Hm, the curtain controller came back spontaneously, just in time to close the curtains at sun down.

manup commented 6 years ago

The curtain controller is a different issue, not fixed in this version. I'm also afraid that it can only be fixed when the controller is a direct child of the gateway since only here the mac capabilities in the neighbor table can be controlled.

ebaauw commented 6 years ago

The curtain controller, lumi.curtain, is a router, not an end device.

I think you're mistaking it for the lumi.ctrl_neutral mains-powered in-wall switch, which is an end device. They have been working fine for me, since I set rx() on receiving the Xiaomi special attribute report (see https://github.com/dresden-elektronik/deconz-rest-plugin/issues/798#issuecomment-427657735).

krombipils commented 6 years ago

In one of my test networks all green lines disappeared albeit all nodes were working,

I noticed the same issue in my setup: Green lines are shown after restart, but after a while almost all green lines are gone. In the meantime some of them reappear (and also disappear again).

manup commented 6 years ago

I think you're mistaking it for the lumi.ctrl_neutral mains-powered in-wall switch, which is an end device. They have been working fine for me, since I set rx() on receiving the Xiaomi special attribute report (see #798 (comment)).

Ah ok yes I meant that one, good to now the rx() helps.

Do you see anything unusual with the lumi.curtain like Nodescriptor or routing stuff which could explain what's happening? Looks like a closer look in sniffer land is needed to see what's going on.

ebaauw commented 6 years ago

No, I haven’t seen anything odd on the lumi.curtain. I haven’t run the sniffer on it for over two weeks.

Updated to 2.05.44 earlier this evening. This version seems to be an improvement over .43 with 0x262d0500 firmware; I think asking for the APS ACK on the default response (to the Xioami special attribute report) is a good call. I’ll let it run for a day ot two, monitoring for lights going unreachable.

ebaauw commented 6 years ago

Running .44 for a day now. Haven't lost any Hue motion sensors. Still lose a light occasionally, but they do come back spontaneously:

Oct 29 20:21:34 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":false}
Oct 29 20:50:53 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":true}
Oct 29 23:58:57 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":false}
Oct 30 00:02:48 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":true}
Oct 30 00:04:51 pi2 dc_eventlog[25553]: /lights/261/state: {"reachable":false}
Oct 30 00:44:44 pi2 dc_eventlog[25553]: /lights/261/state: {"reachable":true}
Oct 30 03:05:11 pi2 dc_eventlog[25553]: /lights/323/state: {"reachable":false}
Oct 30 03:12:18 pi2 dc_eventlog[25553]: /lights/323/state: {"reachable":true}
Oct 30 03:25:46 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":false}
Oct 30 03:37:49 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":true}
Oct 30 03:43:59 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":false}
Oct 30 04:10:01 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":true}
Oct 30 04:53:54 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":false}
Oct 30 04:56:17 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":true}
Oct 30 06:46:44 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":false}
Oct 30 07:11:44 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":true}
Oct 30 13:10:01 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":false}
Oct 30 13:12:28 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":true}
Oct 30 14:50:15 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":false}
Oct 30 15:03:45 pi2 dc_eventlog[25553]: /lights/227/state: {"reachable":true}
Oct 30 15:20:10 pi2 dc_eventlog[25553]: /lights/421/state: {"reachable":true}
Oct 30 15:20:10 pi2 dc_eventlog[25553]: /lights/422/state: {"reachable":true}
Oct 30 18:51:39 pi2 dc_eventlog[25553]: /lights/101/state: {"reachable":true}
Oct 30 19:18:05 pi2 dc_eventlog[25553]: /lights/325/state: {"reachable":true}
Oct 30 19:18:05 pi2 dc_eventlog[25553]: /lights/326/state: {"reachable":true}

The lights are:

manup commented 6 years ago

If you have the chance to sniff the traffic it would be very interesting to look at the Beacon messages of the problematic devices. Especially if all devices have the same Update ID (should be the one configured in deCONZ network settings).

Today I've found that Ikea has some issues here, which could be fixed with a workaround.

My innr bulb did decide to raise the nwkUpdateId on it's own to 22, and shortly after that went totally radio silent. I figure that was after I send the NWK Update request command twice which did contain a nwkUpdateId of 20.

ebaauw commented 5 years ago

Didn’t have time to sniff the problemetic devices, sorry. There’s a different set of problemetic devices on each restart of deCONZ, though.

Now running 2.05.45 and 0x262e0500. I see fewer lights going unreachable, but my Hue motion sensors now take turns losing their connection. Seems worse than under .44 with 2d. I need to reset the sensor and open the network to reconnect it. The good news is that the setup of the reporting configuration is much improved.

ebaauw commented 5 years ago

Lost over half my Hue motion sensors today. Reverting to .44 and 262d.

manup commented 5 years ago

Lost over half my Hue motion sensors today. Reverting to .44 and 262d.

:/ sorry, hope to figure out what's going on there.

I have now joined a Philips hue motions sensor to my mixed test network to check if I can recreate the issues there and sniff around.

Also by next week we are creating a new larger mixed test network at work with many lights, switches and sensors, this should help to recreate problems and iron out bugs a lot.