Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ConBee II disconnects every hour (since 2.05.73?) #2463

Closed
ebaauw opened this issue Feb 17, 2020 · 6 comments
Closed

ConBee II disconnects every hour (since 2.05.73?) #2463

ebaauw opened this issue Feb 17, 2020 · 6 comments

Comments

@ebaauw
Copy link
Collaborator

ebaauw commented Feb 17, 2020

Since two days, the ConBee II on my RaspBerry Pi 4 (running Buster) disconnects every hour. I'm seeing the messages below in the syslog, and the deCONZ GUI shows the device as not in network. After pressing Join, it joins the network again. I double-checked the old logs: the messages didn't appear earlier.

I think this has started after installing 2.05.73. I did a sudo apt update; sudo apt upgrade to install the latest beta, and also got a load of Raspbian updates. I don't see anything similar on the RaspBee on Raspberry 3B+ (still running Stretch).

Not sure if this is related, but I've been playing with emulating the Hue bridge to get the Lutron Aurora to work. After updating, I configured the ConBee II as router, with a custom mac address of 0x0017880101000001 and nwk address of 0x0001 and joined it to my test network.

Here's the first occurrence:

Feb 15 15:28:39 pi5 kernel: [756188.444255] usb 1-1.4: USB disconnect, device number 8
Feb 15 15:28:39 pi5 kernel: [756188.444859] cdc_acm 1-1.4:1.0: failed to set dtr/rts
Feb 15 15:28:39 pi5 kernel: [756188.750759] usb 1-1.4: new full-speed USB device number 10 using xhci_hcd
Feb 15 15:28:40 pi5 kernel: [756188.899781] usb 1-1.4: New USB device found, idVendor=1cf1, idProduct=0030, bcdDevice= 1.00
Feb 15 15:28:40 pi5 kernel: [756188.899789] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 15 15:28:40 pi5 kernel: [756188.899794] usb 1-1.4: Product: ConBee II
Feb 15 15:28:40 pi5 kernel: [756188.899799] usb 1-1.4: Manufacturer: dresden elektronik ingenieurtechnik GmbH
Feb 15 15:28:40 pi5 kernel: [756188.899804] usb 1-1.4: SerialNumber: DE1948490
Feb 15 15:28:40 pi5 kernel: [756188.906459] cdc_acm 1-1.4:1.0: ttyACM1: USB ACM device
Feb 15 15:28:47 pi5 kernel: [756196.380926] usb 1-1.4: USB disconnect, device number 10
Feb 15 15:28:47 pi5 kernel: [756196.730928] usb 1-1.4: new full-speed USB device number 11 using xhci_hcd
Feb 15 15:28:48 pi5 kernel: [756196.870126] usb 1-1.4: New USB device found, idVendor=1cf1, idProduct=0030, bcdDevice= 1.00
Feb 15 15:28:48 pi5 kernel: [756196.870140] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 15 15:28:48 pi5 kernel: [756196.870151] usb 1-1.4: Product: ConBee II
Feb 15 15:28:48 pi5 kernel: [756196.870161] usb 1-1.4: Manufacturer: dresden elektronik ingenieurtechnik GmbH
Feb 15 15:28:48 pi5 kernel: [756196.870171] usb 1-1.4: SerialNumber: DE1948490
Feb 15 15:28:48 pi5 kernel: [756196.880993] cdc_acm 1-1.4:1.0: ttyACM0: USB ACM device

And the two most recent ones (I did reboot in between):

Feb 17 22:38:41 pi5 kernel: [92275.299696] usb 1-1.4: USB disconnect, device number 54
Feb 17 22:38:41 pi5 kernel: [92275.300004] cdc_acm 1-1.4:1.0: failed to set dtr/rts
Feb 17 22:38:41 pi5 kernel: [92275.599520] usb 1-1.4: new full-speed USB device number 55 using xhci_hcd
Feb 17 22:38:41 pi5 kernel: [92275.738556] usb 1-1.4: New USB device found, idVendor=1cf1, idProduct=0030, bcdDevice= 1.00
Feb 17 22:38:41 pi5 kernel: [92275.738563] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 17 22:38:41 pi5 kernel: [92275.738568] usb 1-1.4: Product: ConBee II
Feb 17 22:38:41 pi5 kernel: [92275.738574] usb 1-1.4: Manufacturer: dresden elektronik ingenieurtechnik GmbH
Feb 17 22:38:41 pi5 kernel: [92275.738579] usb 1-1.4: SerialNumber: DE1948490
Feb 17 22:38:41 pi5 kernel: [92275.745216] cdc_acm 1-1.4:1.0: ttyACM1: USB ACM device
Feb 17 22:38:49 pi5 kernel: [92283.236998] usb 1-1.4: USB disconnect, device number 55
Feb 17 22:38:49 pi5 kernel: [92283.539687] usb 1-1.4: new full-speed USB device number 56 using xhci_hcd
Feb 17 22:38:49 pi5 kernel: [92283.678757] usb 1-1.4: New USB device found, idVendor=1cf1, idProduct=0030, bcdDevice= 1.00
Feb 17 22:38:49 pi5 kernel: [92283.678764] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 17 22:38:49 pi5 kernel: [92283.678769] usb 1-1.4: Product: ConBee II
Feb 17 22:38:49 pi5 kernel: [92283.678774] usb 1-1.4: Manufacturer: dresden elektronik ingenieurtechnik GmbH
Feb 17 22:38:49 pi5 kernel: [92283.678779] usb 1-1.4: SerialNumber: DE1948490
Feb 17 22:38:49 pi5 kernel: [92283.685413] cdc_acm 1-1.4:1.0: ttyACM0: USB ACM device
...
Feb 17 23:38:50 pi5 kernel: [95884.427002] usb 1-1.4: USB disconnect, device number 56
Feb 17 23:38:50 pi5 kernel: [95884.427491] cdc_acm 1-1.4:1.0: failed to set dtr/rts
Feb 17 23:38:50 pi5 kernel: [95884.775967] usb 1-1.4: new full-speed USB device number 57 using xhci_hcd
Feb 17 23:38:50 pi5 kernel: [95884.915004] usb 1-1.4: New USB device found, idVendor=1cf1, idProduct=0030, bcdDevice= 1.00
Feb 17 23:38:50 pi5 kernel: [95884.915012] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 17 23:38:50 pi5 kernel: [95884.915017] usb 1-1.4: Product: ConBee II
Feb 17 23:38:50 pi5 kernel: [95884.915023] usb 1-1.4: Manufacturer: dresden elektronik ingenieurtechnik GmbH
Feb 17 23:38:50 pi5 kernel: [95884.915027] usb 1-1.4: SerialNumber: DE1948490
Feb 17 23:38:50 pi5 kernel: [95884.921664] cdc_acm 1-1.4:1.0: ttyACM1: USB ACM device
Feb 17 23:38:58 pi5 kernel: [95892.613955] usb 1-1.4: USB disconnect, device number 57
Feb 17 23:38:58 pi5 kernel: [95892.916264] usb 1-1.4: new full-speed USB device number 58 using xhci_hcd
Feb 17 23:38:58 pi5 kernel: [95893.055240] usb 1-1.4: New USB device found, idVendor=1cf1, idProduct=0030, bcdDevice= 1.00
Feb 17 23:38:58 pi5 kernel: [95893.055250] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 17 23:38:58 pi5 kernel: [95893.055258] usb 1-1.4: Product: ConBee II
Feb 17 23:38:58 pi5 kernel: [95893.055266] usb 1-1.4: Manufacturer: dresden elektronik ingenieurtechnik GmbH
Feb 17 23:38:58 pi5 kernel: [95893.055273] usb 1-1.4: SerialNumber: DE1948490
Feb 17 23:38:58 pi5 kernel: [95893.065948] cdc_acm 1-1.4:1.0: ttyACM0: USB ACM device

After each reconnect, deCONZ tries to pick up, but fails:

Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:39:804 COM: /dev/ttyUSB0 : FT232R USB UART (0x0403/0x6001)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:39:804 COM: /dev/ttyACM0 : ConBee II (0x1CF1/0x0030)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:39:804 COM: /dev/ttyAMA0 :  (0x0000/0x0000)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:39:804 COM: /dev/ttyS0 :  (0x0000/0x0000)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:39:804 dev /dev/ttyS0 (/dev/ttyS0)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:39:805 GW firmware version: 0x264a0700
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:39:805 GW firmware version is up to date: 0x264a0700
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:44:765 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:36:54:766 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:37:04:765 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:37:14:766 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:37:24:765 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:37:34:765 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:37:44:765 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:37:54:765 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:04:766 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:14:765 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:24:766 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:34:765 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:44:767 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:50:766 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:50:766 device state timeout ignored in state 3
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:51:766 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:51:766 device state timeout ignored in state 3
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:52:765 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:52:765 device state timeout ignored in state 3
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:53:765 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:53:766 device state timeout ignored in state 3
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:54:766 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:54:766 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:54:766 device state timeout ignored in state 3
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:55:765 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:55:765 device state timeout (handled)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:55:769 Serial com disconnected, reason: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:56:266 void zmMaster::handleStateIdle(zmMaster::MasterEvent) not connected goto OFF state
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:56:266 device state timeout ignored in state 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:56:766 wait reconnect 15 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:57:766 wait reconnect 14 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:58:766 wait reconnect 13 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:38:59:766 wait reconnect 12 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:00:765 wait reconnect 11 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:01:766 wait reconnect 10 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:02:765 wait reconnect 9 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:03:765 wait reconnect 8 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:04:766 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:04:766 wait reconnect 7 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:05:766 wait reconnect 6 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:06:766 wait reconnect 5 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:07:765 wait reconnect 4 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:08:766 wait reconnect 3 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:09:765 wait reconnect 2 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:10:765 wait reconnect 1 seconds
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:10:804 COM: /dev/ttyUSB0 : FT232R USB UART (0x0403/0x6001)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:10:804 COM: /dev/ttyACM0 : ConBee II (0x1CF1/0x0030)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:10:804 COM: /dev/ttyAMA0 :  (0x0000/0x0000)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:10:804 COM: /dev/ttyS0 :  (0x0000/0x0000)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:10:804 dev /dev/ttyS0 (/dev/ttyS0)
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:10:804 auto connect com /dev/ttyS0
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:10:811 Serial com connected
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:11:288 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:11:288 device state timeout ignored in state 2
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:12:265 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:12:265 device state timeout ignored in state 2
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:13:265 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:13:265 device state timeout ignored in state 2
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:14:266 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:14:266 device state timeout ignored in state 2
Feb 17 23:39:15 pi5 deCONZ[17710]: 23:39:14:766 Daylight now: nightStart, status: 230, daylight: 0, dark: 1
@manup
Copy link
Member

manup commented Feb 18, 2020

This looks like the firmware watchdog gets triggered if no serial communication is received for a while (I think it's an hour).

It also seems that deCONZ selects the wrong device to auto-reconnect to /dev/ttyS0 (albeit it should also cycle through the device list and try with the next after an timeout of 15–20 seconds. Does this happen for /dev/ttyACM0? If not that would be a deCONZ core bug and and a good explanation why some networks go down, I need to check the code here.

If the cycling does not happen, can you please try to pin the device via --dev=/dev/ttyACM0.

After updating, I configured the ConBee II as router, with a custom mac address of 0x0017880101000001 and nwk address of 0x0001 and joined it to my test network.

To be honest I'm not sure, there is some isCoordinator() magic in the code and the REST-API plugin which might lead to different code paths. I haven't tested the router configuration in a while now.

@ebaauw
Copy link
Collaborator Author

ebaauw commented Feb 18, 2020

This looks like the firmware watchdog gets triggered if no serial communication is received for a while (I think it's an hour).

Odd. The network consists of (from top to bottom):

  • Lutron Aurora.
  • Hue light;
  • XBee;
  • ConBee II;
  • RaspBee (coordinator);

This screenshot is from the GUI connected to the ConBee II:
Screenshot 2020-02-18 at 09 57
I cleared the database; the REST API plugin doesn't know any of the devices (other than the ConBee II), so I wouldn't generate any ZigBee traffic. However, I would expect the deCONZ core to poll the routers for their neighbour tables (after all, the lines are drawn). I do see ZDP requests for cluster 0x0031 in the deCONZ log.

Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:43:766 Daylight now: goldenHour1, status: 160, daylight: 1, dark: 0
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:43:766 unsupported device type 1 (TODO)
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:45:041 APS-DATA.request id: 134, addrmode: 0x03, addr: 0x0017880101000001, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:45:053 APS-DATA.confirm id: 134, status: 0x00 SUCCESS
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:45:053 APS-DATA.confirm request id: 134 -> confirmed, timeout 8757592
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:45:058 APS-DATA.indication srcAddr: 0x0001, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 142, rssi: 41
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:45:058 #011asdu: 20000302011e0401ffff2e2100ff2c34040188170001c3050002ff
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:45:058 APS-DATA.indication request id: 134 -> finished
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:45:058 APS-DATA.request id: 134 erase from queue
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:45:058 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0001
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:47:442 APS-DATA.request id: 147, addrmode: 0x03, addr: 0x0017880104342cff, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:47:461 APS-DATA.confirm id: 147, status: 0x00 SUCCESS
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:47:461 APS-DATA.confirm request id: 147 -> confirmed, timeout 10191088
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:47:482 APS-DATA.indication srcAddr: 0xc301, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 255, rssi: -55
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:47:482 #011asdu: 23000600021e0401ffff2e2100ae1c834100a21300d5ca050101ec1e0401ffff2e21001e0401ffff2e21000000340100d4
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:47:482 APS-DATA.indication request id: 147 -> finished
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:47:482 APS-DATA.request id: 147 erase from queue
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:49:841 APS-DATA.request id: 161, addrmode: 0x03, addr: 0x0017880104342cff, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:49:862 APS-DATA.confirm id: 161, status: 0x00 SUCCESS
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:49:862 APS-DATA.confirm request id: 161 -> confirmed, timeout 10191088
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:49:904 APS-DATA.indication srcAddr: 0xc301, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 255, rssi: -55
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:49:904 #011asdu: 26000602021e0401ffff2e210001000001018817000100350003ff1e0401ffff2e210003554910018817002f1a12000300
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:49:904 APS-DATA.indication request id: 161 -> finished
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:49:904 APS-DATA.request id: 161 erase from queue
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:49:904 neigbor 0x0017880110495503 is unknown child
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:52:242 APS-DATA.request id: 174, addrmode: 0x03, addr: 0x0017880104342cff, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:52:259 APS-DATA.confirm id: 174, status: 0x00 SUCCESS
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:52:259 APS-DATA.confirm request id: 174 -> confirmed, timeout 10191088
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:52:301 APS-DATA.indication srcAddr: 0xc301, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 255, rssi: -55
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:52:301 #011asdu: 29000604021e0401ffff2e2100a7d403ffff2e21000100350102001e0401ffff2e210008e9fde70f00ffff439a120003cf
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:52:301 APS-DATA.indication request id: 174 -> finished
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:52:301 APS-DATA.request id: 174 erase from queue
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:52:301 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0xC301
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:53:765 Daylight now: goldenHour1, status: 160, daylight: 1, dark: 0
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:53:765 unsupported device type 1 (TODO)
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:54:642 APS-DATA.request id: 190, addrmode: 0x03, addr: 0x00212effff01041e, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:54:660 APS-DATA.confirm id: 190, status: 0x00 SUCCESS
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:54:660 APS-DATA.confirm request id: 190 -> confirmed, timeout 8756336
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:54:675 APS-DATA.indication srcAddr: 0x0000, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 207, rssi: -68
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:54:675 #011asdu: 2e000300011e0401ffff2e2100ff2c34040188170001c3350100f7
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:54:676 APS-DATA.indication request id: 190 -> finished
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:54:676 APS-DATA.request id: 190 erase from queue
Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:56:266 Idle timer triggered

Note the line:

Feb 18 10:15:57 pi5 deCONZ[30000]: 10:15:53:765 unsupported device type 1 (TODO)

Haven't seen that before.

The RaspBee sees:
Screenshot 2020-02-18 at 09 58
It's REST API plugin polls the Hue light alright.

I double-checked that I can read the attributes of the ConBee II's Time cluster from the RaspBee and v.v.

If the cycling does not happen, can you please try to pin the device via --dev=/dev/ttyACM0.

Done.

BTW: I see the OTAU plugin now supports sorting on columns! Cool!

@ebaauw
Copy link
Collaborator Author

ebaauw commented Feb 18, 2020

there is some isCoordinator() magic in the code

Indeed. That explains the unsupported device type 1 (TODO) message.

deconz-rest-plugin/change_channel.cpp

Lines 443 to 447 in edf380f

else if (deviceType != deCONZ::Coordinator)
{
DBG_Printf(DBG_INFO, "unsupported device type %u (TODO)\n", deviceType);
return;
}

@ebaauw
Copy link
Collaborator Author

ebaauw commented Feb 18, 2020

OK, had another disconnect/reconnect, but the --dev pinning seems to do the trick.

Feb 18 10:40:25 pi5 deCONZ[30000]: 10:40:23:766 Daylight now: goldenHour1, status: 160, daylight: 1, dark: 0
Feb 18 10:40:25 pi5 deCONZ[30000]: 10:40:23:766 unsupported device type 1 (TODO)
Feb 18 10:40:25 pi5 deCONZ[30000]: 10:40:25:842 APS-DATA.request id: 198, addrmode: 0x03, addr: 0x0017880101000001, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
Feb 18 10:40:25 pi5 deCONZ[30000]: 10:40:25:853 APS-DATA.confirm id: 198, status: 0x00 SUCCESS
Feb 18 10:40:25 pi5 deCONZ[30000]: 10:40:25:853 APS-DATA.confirm request id: 198 -> confirmed, timeout 10518888
Feb 18 10:40:25 pi5 deCONZ[30000]: 10:40:25:858 APS-DATA.indication srcAddr: 0x0001, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 149, rssi: 41
Feb 18 10:40:25 pi5 deCONZ[30000]: 10:40:25:858 #011asdu: b1000302011e0401ffff2e2100ff2c34040188170001c3050002ff
Feb 18 10:40:27 pi5 kernel: [135582.209825] usb 1-1.4: USB disconnect, device number 78
Feb 18 10:40:27 pi5 kernel: [135582.210334] cdc_acm 1-1.4:1.0: failed to set dtr/rts
Feb 18 10:40:27 pi5 kernel: [135582.521476] usb 1-1.4: new full-speed USB device number 79 using xhci_hcd
Feb 18 10:40:27 pi5 kernel: [135582.670468] usb 1-1.4: New USB device found, idVendor=1cf1, idProduct=0030, bcdDevice= 1.00
Feb 18 10:40:27 pi5 kernel: [135582.670476] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 18 10:40:27 pi5 kernel: [135582.670481] usb 1-1.4: Product: ConBee II
Feb 18 10:40:27 pi5 kernel: [135582.670487] usb 1-1.4: Manufacturer: dresden elektronik ingenieurtechnik GmbH
Feb 18 10:40:27 pi5 kernel: [135582.670491] usb 1-1.4: SerialNumber: DE1948490
Feb 18 10:40:27 pi5 kernel: [135582.677127] cdc_acm 1-1.4:1.0: ttyACM1: USB ACM device
Feb 18 10:40:27 pi5 mtp-probe: checking bus 1, device 79: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4"
Feb 18 10:40:27 pi5 mtp-probe: bus: 1, device: 79 was not an MTP device
Feb 18 10:40:27 pi5 mtp-probe: checking bus 1, device 79: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4"
Feb 18 10:40:27 pi5 mtp-probe: bus: 1, device: 79 was not an MTP device
Feb 18 10:40:35 pi5 kernel: [135590.147154] usb 1-1.4: USB disconnect, device number 79
Feb 18 10:40:35 pi5 kernel: [135590.441647] usb 1-1.4: new full-speed USB device number 80 using xhci_hcd
Feb 18 10:40:35 pi5 kernel: [135590.580670] usb 1-1.4: New USB device found, idVendor=1cf1, idProduct=0030, bcdDevice= 1.00
Feb 18 10:40:35 pi5 kernel: [135590.580678] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 18 10:40:35 pi5 kernel: [135590.580684] usb 1-1.4: Product: ConBee II
Feb 18 10:40:35 pi5 kernel: [135590.580689] usb 1-1.4: Manufacturer: dresden elektronik ingenieurtechnik GmbH
Feb 18 10:40:35 pi5 kernel: [135590.580694] usb 1-1.4: SerialNumber: DE1948490
Feb 18 10:40:35 pi5 kernel: [135590.589349] cdc_acm 1-1.4:1.0: ttyACM0: USB ACM device
Feb 18 10:40:35 pi5 mtp-probe: checking bus 1, device 80: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4"
Feb 18 10:40:35 pi5 mtp-probe: bus: 1, device: 80 was not an MTP device
Feb 18 10:40:35 pi5 mtp-probe: checking bus 1, device 80: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4"
Feb 18 10:40:35 pi5 mtp-probe: bus: 1, device: 80 was not an MTP device
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:25:858 APS-DATA.indication request id: 198 -> finished
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:25:858 APS-DATA.request id: 198 erase from queue
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:25:858 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x0001
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:26:266 Idle timer triggered
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:27:605 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:27:605 device state timeout ignored in state 3
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:28:241 APS-DATA.request id: 214, addrmode: 0x03, addr: 0x0017880104342cff, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:28:655 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:28:655 device state timeout ignored in state 3
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:29:706 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:29:706 device state timeout ignored in state 3
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:30:755 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:30:755 device state timeout ignored in state 3
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:31:765 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:31:765 device state timeout ignored in state 3
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:32:766 void zmMaster::handleStateStatus(zmMaster::MasterEvent) EVENT_TIMEOUT
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:32:766 device state timeout (handled)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:32:773 Serial com disconnected, reason: 1
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:32:817 aps request id: 214 prf: 0x0000 cl: 0x0031 timeout (confirmed: 0) to 0x0017880104342CFF (0xC301)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:32:817 aps request id: 214 prf: 0x0000 cl: 0x0031 timeout NOT confirmed to 0x0017880104342CFF (0xC301)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:32:881 aps request id: 214 failed, erase from queue
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:32:881 emit artificial APSDE-DATA.confirm id: 214
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:32:961 aps request id: 214 failed, erase from queue
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:33:265 networkState: CC_ReconnectNetwork
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:33:265 start reconnect to network
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:33:265 void zmMaster::handleStateIdle(zmMaster::MasterEvent) not connected goto OFF state
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:33:265 device state timeout ignored in state 1
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:33:765 Daylight now: goldenHour1, status: 160, daylight: 1, dark: 0
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:33:765 wait reconnect 15 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:34:765 wait reconnect 14 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:35:766 wait reconnect 13 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:36:765 wait reconnect 12 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:37:766 wait reconnect 11 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:38:516 failed to reconnect to network try=1
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:38:765 wait reconnect 10 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:39:765 wait reconnect 9 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:40:765 wait reconnect 8 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:41:765 wait reconnect 7 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:42:765 wait reconnect 6 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:43:765 Daylight now: goldenHour1, status: 160, daylight: 1, dark: 0
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:43:765 failed to reconnect to network try=2
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:43:765 wait reconnect 5 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:44:765 wait reconnect 4 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:45:765 wait reconnect 3 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:46:765 wait reconnect 2 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:765 wait reconnect 1 seconds
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:803 COM: /dev/ttyUSB0 : FT232R USB UART (0x0403/0x6001)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:803 COM: /dev/ttyACM0 : ConBee II (0x1CF1/0x0030)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:803 COM: /dev/ttyAMA0 :  (0x0000/0x0000)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:803 COM: /dev/ttyS0 :  (0x0000/0x0000)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:803 dev /dev/ttyS0 (/dev/ttyS0)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:803 COM: /dev/ttyACM0 / serialno: DE1948490
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:803 COM: --dev: /dev/ttyACM0 (ConBee II)
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:804 auto connect com /dev/ttyACM0
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:806 Serial com connected
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:809 Master: read param with arg 0x18
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:809 Master: read param with arg 0x13
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:809 Master: read param with arg 0x13
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:809 Master: read param with arg 0x18
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:809 Master: read param with arg 0x13
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:809 Master: read param with arg 0x13
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:818 Master: read param with arg 0x18
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:818 Master: read param with arg 0x13
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:818 Master: read param with arg 0x13
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:868 Device firmware version 0x264A0700
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:870 unlocked max nodes: 200
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:870 has feature: max nodes (0x11), status: 0x00
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:874 has feature: std security (0x01), status: 0x04
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:878 has feature: link security (0x02), status: 0x00
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:882 has feature: high security (0x03), status: 0x04
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:886 has feature: ethernet (0x04), status: 0x04
Feb 18 10:40:47 pi5 deCONZ[30000]: 10:40:47:890 has feature: mass storage device (MSD) (0x05), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:894 has feature: device firmware upgrade (DFU) (0x06), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:898 has feature: ZigBee Light Link (ZLL) (0x07), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:902 has feature: interpan (0x08), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:906 has feature: button 1 (0x09), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:910 has feature: button 1 (0x0A), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:914 has feature: LED 1 (0x0B), status: 0x00
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:918 has feature: LED 2 (0x0C), status: 0x00
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:922 has feature: LED 3 (0x0D), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:926 has feature: LED 4 (0x0E), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:930 has feature: LED 5 (0x0F), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:934 has feature: LED RGB (0x10), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:938 has feature: max nodes (0x11), status: 0x04
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:942 Device protocol version: 0x010B
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:958 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 1, node: 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:47:990 Current channel 11
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:002 CTRL got nwk update id 0
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:006 CTRL ANT_CTRL 0x03
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:030 Device protocol version: 0x010B
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:046 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 1, node: 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:078 Current channel 11
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:090 CTRL got nwk update id 0
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:094 CTRL ANT_CTRL 0x03
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:118 Device protocol version: 0x010B
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:134 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 1, node: 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:166 Current channel 11
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:178 CTRL got nwk update id 0
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:182 CTRL ANT_CTRL 0x03
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:206 NET ZDO start network status 0xC3
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:766 try to reconnect to network try=3
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:768 Master: read param with arg 0x18
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:768 Master: read param with arg 0x13
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:768 Master: read param with arg 0x13
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:772 Device protocol version: 0x010B
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:787 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 1, node: 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:819 Current channel 11
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:831 CTRL got nwk update id 0
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:48:835 CTRL ANT_CTRL 0x03
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:346 APS-DATA.indication srcAddr: 0x0001, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x0013, lqi: 255, rssi: -55
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:346 #011asdu: 00010001000001018817008e
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:346 0xFFFF nwk changed to 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:995 DEV config changed event
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:995 Master: read param with arg 0x18
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:995 Master: read param with arg 0x13
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:995 Master: read param with arg 0x13
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:996 Master: read param with arg 0x18
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:996 Master: read param with arg 0x13
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:996 Master: read param with arg 0x13
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:49:000 Device protocol version: 0x010B
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:004 APS-DATA.request id: 239, addrmode: 0x02, addr: 0x0001, profile: 0x0000, cluster: 0x0005, ep: 0x00 -> 0x00 queue: 0 len: 3 tx.options 0x00
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:015 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 1, node: 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:047 Current channel 11
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:059 CTRL got nwk update id 0
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:063 CTRL ANT_CTRL 0x03
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:081 ZDP discovery done in 735 ms10:40:50:087 Device protocol version: 0x010B
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:103 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 1, node: 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:135 Current channel 11
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:147 CTRL got nwk update id 0
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:151 CTRL ANT_CTRL 0x03
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:179 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 1, node: 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:201 APS-DATA.confirm id: 214, status: 0x00 SUCCESS
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:201 APS-DATA.confirm id: 214, status: 0x00, match: 0
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:205 APS-DATA.confirm id: 239, status: 0x00 SUCCESS
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:205 APS-DATA.confirm request id: 239 -> confirmed, timeout 10733520
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:209 APS-DATA.indication srcAddr: 0x0001, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8005, lqi: 133, rssi: 28
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:209 #011asdu: bd000100020141
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:209 APS-DATA.indication request id: 239 -> finished
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:209 APS-DATA.request id: 239 erase from queue
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:209 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 7, node: 0x0001
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:231 APS-DATA.indication srcAddr: 0xc301, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 255, rssi: -55
Feb 18 10:40:52 pi5 deCONZ[30000]: 10:40:50:231 #011asdu: b7000600021e0401ffff2e2100ae1c834100a21300d5ca050101ec1e0401ffff2e21001e0401ffff2e21000000340100d4
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:52:641 APS-DATA.request id: 2, addrmode: 0x03, addr: 0x0017880104342cff, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:52:663 APS-DATA.confirm id: 2, status: 0x00 SUCCESS
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:52:663 APS-DATA.confirm request id: 2 -> confirmed, timeout 10733600
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:52:685 APS-DATA.indication srcAddr: 0xc301, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8031, lqi: 255, rssi: -55
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:52:685 #011asdu: c3000602021e0401ffff2e210001000001018817000100350003ff1e0401ffff2e210003554910018817002f1a12000300
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:52:685 APS-DATA.indication request id: 2 -> finished
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:52:685 APS-DATA.request id: 2 erase from queue
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:52:686 neigbor 0x0017880110495503 is unknown child
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:53:766 Daylight now: goldenHour1, status: 160, daylight: 1, dark: 0
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:53:766 unsupported device type 1 (TODO)
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:53:766 reconnect network done
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:482 APS-DATA.request id: 14, addrmode: 0x02, addr: 0x0001, profile: 0x0000, cluster: 0x0001, ep: 0x00 -> 0x00 queue: 0 len: 5 tx.options 0x00
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:493 APS-DATA.confirm id: 14, status: 0x00 SUCCESS
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:493 APS-DATA.confirm request id: 14 -> confirmed, timeout 10733520
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:497 APS-DATA.indication srcAddr: 0x0001, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x0001, lqi: 149, rssi: 41
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:497 #011asdu: c701000000
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:497 APS-DATA.request id: 16, addrmode: 0x02, addr: 0x0001, profile: 0x0000, cluster: 0x8001, ep: 0x00 -> 0x00 queue: 1 len: 12 tx.options 0x04
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:501 APS-DATA.indication srcAddr: 0x0001, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 149, rssi: 41
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:501 #011asdu: c70001000001018817000100
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:501 APS-DATA.indication request id: 14 -> finished
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:501 APS-DATA.request id: 14 erase from queue
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:501 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 2, node: 0x0001
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:514 APS-DATA.confirm id: 16, status: 0x00 SUCCESS
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:518 APS-DATA.indication srcAddr: 0x0001, srcEp: 0x00 dstAddrMode: 2, profile: 0x0000, cluster: 0x8001, lqi: 149, rssi: 41
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:518 #011asdu: c70001000001018817000100
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:518 APS-DATA.request id: 16 erase from queue
Feb 18 10:40:57 pi5 deCONZ[30000]: 10:40:54:518 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 2, node: 0x0001

@ebaauw
Copy link
Collaborator Author

ebaauw commented Feb 18, 2020

Not sure if this is related, but I've been playing with emulating the Hue bridge to get the Lutron Aurora to work. After updating, I configured the ConBee II as router, with a custom mac address of 0x0017880101000001 and nwk address of 0x0001 and joined it to my test network.

To be honest I'm not sure, there is some isCoordinator() magic in the code and the REST-API plugin which might lead to different code paths. I haven't tested the router configuration in a while now.

Definitely related. After reconfiguring the ConBee II to its original settings, I no longer see the disconnect messages.

@ebaauw ebaauw closed this as completed Feb 18, 2020
@manup
Copy link
Member

manup commented Feb 19, 2020

Good catch, I think this should be fixed later on. The router configuration is quite useful at times.

For the reconnect issue I have checked the code and found some spots which were causing the cycling through all devices to stop. This is fixed now and available in the next build.

@ebaauw ebaauw mentioned this issue Feb 25, 2020
Closed
@ndfred ndfred mentioned this issue Dec 23, 2020
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@manup @ebaauw