search

hobbyquaker / node-red-contrib-zigbee

Node-RED Nodes for ZigBee Devices 🐝
MIT License
86 stars 15 forks source link

Error: SRSP - ZDO - mgmtPermitJoinReq after 6000ms (SOLVED) #158

Closed TomBraun closed 3 years ago

TomBraun commented 3 years ago

permitJoin does not work as expected.

System: Raspberrymatic with RedMatic 

dmesg:
[Tue Oct  5 12:06:24 2021] usb 1-1.2: new high-speed USB device number 6 using xhci_hcd
[Tue Oct  5 12:06:24 2021] usb 1-1.2: New USB device found, idVendor=0451, idProduct=bef3, bcdDevice= 1.00
[Tue Oct  5 12:06:24 2021] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[Tue Oct  5 12:06:24 2021] usb 1-1.2: Product: XDS110 (03.00.00.16) Embed with CMSIS-DAP
[Tue Oct  5 12:06:24 2021] usb 1-1.2: Manufacturer: Texas Instruments
[Tue Oct  5 12:06:24 2021] usb 1-1.2: SerialNumber: L1100G8T
[Tue Oct  5 12:06:24 2021] cdc_acm 1-1.2:1.0: ttyACM0: USB ACM device
[Tue Oct  5 12:06:24 2021] cdc_acm 1-1.2:1.3: ttyACM1: USB ACM device
[Tue Oct  5 12:06:24 2021] hid-generic 0003:0451:BEF3.0003: hiddev96,hidraw0: USB HID v1.11 Device [Texas Instruments XDS110 (03.00.00.16) Embed with CMSIS-DAP] on usb-0000:01:00.0-1.2/input5

log:
Oct  5 12:06:29 homematic-raspi daemon.info node-red[1401]: [zigbee-shepherd:zigbee] connecting /dev/ttyACM0 undefined
Oct  5 12:06:30 homematic-raspi daemon.err node-red: 2021-10-05T10:06:30.846Z zigbee-herdsman:adapter:zStack:startZnp Item 'hasConfigured' is valid
Oct  5 12:06:30 homematic-raspi daemon.err node-red: 2021-10-05T10:06:30.861Z zigbee-herdsman:adapter:zStack:startZnp Item 'hasConfigured' is valid
Oct  5 12:06:30 homematic-raspi daemon.err node-red: 2021-10-05T10:06:30.879Z zigbee-herdsman:adapter:zStack:startZnp Item 'channelList' is valid
Oct  5 12:06:30 homematic-raspi daemon.err node-red: 2021-10-05T10:06:30.895Z zigbee-herdsman:adapter:zStack:startZnp Item 'networkKeyDistribute' is valid
Oct  5 12:06:30 homematic-raspi daemon.err node-red: 2021-10-05T10:06:30.912Z zigbee-herdsman:adapter:zStack:startZnp Item 'networkKey' is valid
Oct  5 12:06:30 homematic-raspi daemon.err node-red: 2021-10-05T10:06:30.927Z zigbee-herdsman:adapter:zStack:startZnp Item 'panID' is valid
Oct  5 12:06:30 homematic-raspi daemon.err node-red: 2021-10-05T10:06:30.944Z zigbee-herdsman:adapter:zStack:startZnp Item 'extendedPanID' is valid
Oct  5 12:06:30 homematic-raspi daemon.err node-red: 2021-10-05T10:06:30.953Z zigbee-herdsman:adapter:zStack:startZnp Start ZNP as coordinator...
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.619Z zigbee-herdsman:adapter:zStack:startZnp ZNP started as coordinator
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.627Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '1'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.632Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '2'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.637Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '3'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.642Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '4'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.646Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '5'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.651Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '6'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.656Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '8'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.661Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '10'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.666Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '11'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.671Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '110'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.676Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '12'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.680Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '13'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.685Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '47'
Oct  5 12:06:33 homematic-raspi daemon.err node-red: 2021-10-05T10:06:33.690Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '242'
Oct  5 12:06:33 homematic-raspi daemon.info node-red[1401]: [zigbee-shepherd:zigbee] Currently 0 devices are joined:
Oct  5 12:06:34 homematic-raspi daemon.info node-red[1401]: [zigbee-shepherd:zigbee] Zigbee network parameters: {"panID":65450,"extendedPanID":"0xdddddddddddddddd","channel":11}
Oct  5 12:06:34 homematic-raspi daemon.info node-red[1401]: [zigbee-shepherd:zigbee] Coordinator: zStack3x0 2.7.1 20210708
Oct  5 12:18:12 homematic-raspi daemon.info node-red[1401]: [zigbee-shepherd:zigbee] permitJoin true
Oct  5 12:18:18 homematic-raspi daemon.err node-red: (node:1401) UnhandledPromiseRejectionWarning: Error: SRSP - ZDO - mgmtPermitJoinReq after 6000ms
Oct  5 12:18:18 homematic-raspi daemon.err node-red:     at Timeout._onTimeout (/usr/local/addons/redmatic/lib/node_modules/node-red-contrib-zigbee/node_modules/zigbee-herdsman/dist/utils/waitress.js:67:35)
Oct  5 12:18:18 homematic-raspi daemon.err node-red:     at listOnTimeout (internal/timers.js:554:17)
Oct  5 12:18:18 homematic-raspi daemon.err node-red:     at processTimers (internal/timers.js:497:7)
Oct  5 12:18:18 homematic-raspi daemon.err node-red: (node:1401) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)
Oct  5 12:18:18 homematic-raspi daemon.err node-red: (node:1401) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
Sineos commented 3 years ago

Make sure your PanID is 4 characters and Network Key is 32 characters in valid hex notation (A-F and 0-9).

TomBraun commented 3 years ago

Thanks for your help. The PenID should be a hex number, right? 6722 should be allowed, but it is marked red.

I have attached a screenshot zigbee

Sineos commented 3 years ago

The PenID should be a hex number, right? 6722 should be allowed, but it is marked red.

Yes, should work. In my experience it seems a bit touchy WRT the PanID. Try something along the standard 1A62 or 1A63 extPanId is not used. Best to leave it unmodified.

TomBraun commented 3 years ago

I have to stop CUxD !!!

Before I stop the daemon:

Oct  6 17:48:19 homematic-raspi daemon.info node-red[7907]: [zigbee-shepherd:zigbee] connecting /dev/serial/by-id/usb-Texas_Instruments_XDS110__03.00.00.16__Embed_with_CMSIS-DAP_L1100G8T-if00 undefined
Oct  6 17:48:20 homematic-raspi daemon.err node-red: 2021-10-06T15:48:20.813Z zigbee-herdsman:adapter:zStack:startZnp Item 'hasConfigured' is valid
Oct  6 17:48:20 homematic-raspi daemon.err node-red: 2021-10-06T15:48:20.827Z zigbee-herdsman:adapter:zStack:startZnp Item 'hasConfigured' is valid
Oct  6 17:48:20 homematic-raspi daemon.err node-red: 2021-10-06T15:48:20.844Z zigbee-herdsman:adapter:zStack:startZnp Item 'channelList' is valid
Oct  6 17:48:20 homematic-raspi daemon.err node-red: 2021-10-06T15:48:20.860Z zigbee-herdsman:adapter:zStack:startZnp Item 'networkKeyDistribute' is valid
Oct  6 17:48:20 homematic-raspi daemon.err node-red: 2021-10-06T15:48:20.879Z zigbee-herdsman:adapter:zStack:startZnp Item 'networkKey' is valid
Oct  6 17:48:20 homematic-raspi daemon.err node-red: 2021-10-06T15:48:20.892Z zigbee-herdsman:adapter:zStack:startZnp Item 'panID' is valid
Oct  6 17:48:20 homematic-raspi daemon.err node-red: 2021-10-06T15:48:20.908Z zigbee-herdsman:adapter:zStack:startZnp Item 'extendedPanID' is valid
Oct  6 17:48:20 homematic-raspi daemon.err node-red: 2021-10-06T15:48:20.917Z zigbee-herdsman:adapter:zStack:startZnp Start ZNP as coordinator...
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.260Z zigbee-herdsman:adapter:zStack:startZnp ZNP started as coordinator
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.270Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '1'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.275Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '2'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.279Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '3'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.284Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '4'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.288Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '5'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.293Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '6'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.298Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '8'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.303Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '10'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.309Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '11'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.314Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '110'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.319Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '12'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.324Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '13'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.328Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '47'
Oct  6 17:48:23 homematic-raspi daemon.err node-red: 2021-10-06T15:48:23.333Z zigbee-herdsman:adapter:zStack:startZnp Registering endpoint '242'
Oct  6 17:48:23 homematic-raspi daemon.info node-red[7907]: [zigbee-shepherd:zigbee] Currently 0 devices are joined:
Oct  6 17:48:23 homematic-raspi daemon.info node-red[7907]: [zigbee-shepherd:zigbee] Zigbee network parameters: {"panID":6755,"extendedPanID":"0xdddddddddddddddd","channel":12}
Oct  6 17:48:23 homematic-raspi daemon.info node-red[7907]: [zigbee-shepherd:zigbee] Coordinator: zStack3x0 2.7.1 20210708

Oct  6 17:48:29 homematic-raspi daemon.info cuxd[859]: USB(1-1.2/ttyACM0) XDS110 (03.00.00.16) Embed with CMSIS-DAP connect(9600:8N1)
Oct  6 17:48:29 homematic-raspi daemon.info cuxd[859]: USB(1-1.2+3/ttyACM1) XDS110 (03.00.00.16) Embed with CMSIS-DAP connect(9600:8N1)

Oct  6 17:49:00 homematic-raspi daemon.info node-red[7907]: [zigbee-shepherd:zigbee] permitJoin true
Oct  6 17:49:06 homematic-raspi daemon.err node-red: (node:7907) UnhandledPromiseRejectionWarning: Error: SRSP - ZDO - mgmtPermitJoinReq after 6000ms
Oct  6 17:49:06 homematic-raspi daemon.err node-red:     at Timeout._onTimeout (/usr/local/addons/redmatic/lib/node_modules/node-red-contrib-zigbee/node_modules/zigbee-herdsman/dist/utils/waitress.js:67:35)
Oct  6 17:49:06 homematic-raspi daemon.err node-red:     at listOnTimeout (internal/timers.js:554:17)
Oct  6 17:49:06 homematic-raspi daemon.err node-red:     at processTimers (internal/timers.js:497:7)
Oct  6 17:49:06 homematic-raspi daemon.err node-red: (node:7907) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)
Oct  6 17:49:06 homematic-raspi daemon.err node-red: (node:7907) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

After stop the daemon

Oct  6 17:51:07 homematic-raspi daemon.info cuxd[859]: CUx-Daemon stop(2)
Oct  6 17:51:07 homematic-raspi daemon.info cuxd[859]: remove(/var/cache/cuxd_proxy.ini)
Oct  6 17:51:07 homematic-raspi daemon.info cuxd[859]: save paramsets(/usr/local/addons/cuxd/cuxd.ps) size:14
Oct  6 17:51:07 homematic-raspi daemon.info cuxd[859]: USB(1-1.2/ttyACM0) XDS110 (03.00.00.16) Embed with CMSIS-DAP disconnect
Oct  6 17:51:07 homematic-raspi daemon.info cuxd[859]: USB(1-1.2+3/ttyACM1) XDS110 (03.00.00.16) Embed with CMSIS-DAP disconnect
Oct  6 17:51:07 homematic-raspi daemon.info cuxd[859]: remove(/var/run/cuxd.pid)

Oct  6 17:53:29 homematic-raspi daemon.info node-red[9688]: [zigbee-shepherd:zigbee] connecting /dev/serial/by-id/usb-Texas_Instruments_XDS110__03.00.00.16__Embed_with_CMSIS-DAP_L1100G8T-if00 undefined
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.333Z zigbee-herdsman:adapter:zStack:startZnp Item 'hasConfigured' is valid
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.347Z zigbee-herdsman:adapter:zStack:startZnp Item 'hasConfigured' is valid
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.365Z zigbee-herdsman:adapter:zStack:startZnp Item 'channelList' is valid
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.381Z zigbee-herdsman:adapter:zStack:startZnp Item 'networkKeyDistribute' is valid
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.399Z zigbee-herdsman:adapter:zStack:startZnp Item 'networkKey' is valid
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.412Z zigbee-herdsman:adapter:zStack:startZnp Item 'panID' is valid
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.429Z zigbee-herdsman:adapter:zStack:startZnp Item 'extendedPanID' is valid
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.437Z zigbee-herdsman:adapter:zStack:startZnp ZNP is already started as coordinator
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.449Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '1' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.449Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '2' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.449Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '3' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.449Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '4' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '5' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '6' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '8' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '10' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '11' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '110' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '12' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '13' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '47' already registered
Oct  6 17:53:32 homematic-raspi daemon.err node-red: 2021-10-06T15:53:32.450Z zigbee-herdsman:adapter:zStack:startZnp Endpoint '242' already registered
Oct  6 17:53:32 homematic-raspi daemon.info node-red[9688]: [zigbee-shepherd:zigbee] Currently 0 devices are joined:
Oct  6 17:53:32 homematic-raspi daemon.info node-red[9688]: [zigbee-shepherd:zigbee] Zigbee network parameters: {"panID":6755,"extendedPanID":"0xdddddddddddddddd","channel":12}
Oct  6 17:53:32 homematic-raspi daemon.info node-red[9688]: [zigbee-shepherd:zigbee] Coordinator: zStack3x0 2.7.1 20210708
Oct  6 17:54:18 homematic-raspi daemon.info node-red[9688]: [zigbee-shepherd:zigbee] permitJoin true
Oct  6 17:55:05 homematic-raspi daemon.info node-red[9688]: [zigbee-shepherd:zigbee] deviceJoined 0x00158d00041bc628
Oct  6 17:55:05 homematic-raspi daemon.info node-red[9688]: [zigbee-shepherd:zigbee] deviceInterview started 0x00158d00041bc628
Sineos commented 3 years ago

Ah, makes sense. This is a known issue. CUxD grabs the USB serial port. See https://github.com/hobbyquaker/node-red-contrib-zigbee/issues/21#issuecomment-489188813