• State Resolved
  • Locked Locked
  • Replies 8 replies
  • Subscribers 56 subscribers
  • Views 761 views
  • Users 0 members are here
Support feedback
Options
Options
Related

This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

CC2530: Difficulties to remove devices from the gateway - restart needed - and other related issues - ZIGBEE-LINUX-SENSOR-TO-CLOUD_1.0.1

Mario DW
Genius 3145 points
Part Number: CC2530
Other Parts Discussed in Thread: Z-STACK

I couldn' tremove all devices in a single "Gateway session". I generally can remove 2 or 3 devices, but then the gateway must be restarted.

I had to restart the gateway in order to complete the deletion before doing a hard reset.

**** For information, the grep command that provide the log extract (that I then reduced further manually):
egrep '(NWK_REMOVE_DEVICE_REQ|_APS|NWK_MGR/LSTN.*ieeeAddr =|RESET|missing|parentAddr =|nwkAddr)' RestartRequiredToRemoveDevice.log
**** Some of the TC Device Indications with network addresses:
[2020-11-21 03:44:53.157959] [Z_STACK/HNDL] INFO : zstackpb Sending TC Device Ind: nwkAddr:0xE1B7, extAddr:0xCCCCCCFFFE3A2F33, parentAddr:0x0000
[2020-11-21 03:44:56.456502] [Z_STACK/HNDL] INFO : zstackpb Sending TC Device Ind: nwkAddr:0xBAC8, extAddr:0x000D6F0012199E48, parentAddr:0x0000
[2020-11-21 03:45:54.978735] [Z_STACK/HNDL] INFO : zstackpb Sending TC Device Ind: nwkAddr:0xD34C, extAddr:0x00124B000760BB0A, parentAddr:0x0000
[2020-11-21 04:17:31.523794] [Z_STACK/HNDL] INFO : zstackpb Sending TC Device Ind: nwkAddr:0x1017, extAddr:0x00158D00047B8369, parentAddr:0x0000
**** some information about the remove request recieved by the NWK_MGR and the request sent to the ZNP
[2020-11-21 15:47:35.418681] [NWK_MGR/LSTN] PKTBODY: cmdId = NWK_REMOVE_DEVICE_REQ
[2020-11-21 15:47:35.419072] [NWK_MGR/LSTN] PKTBODY: ieeeAddr = 00:12:4B:00:07:60:BB:0A
[2020-11-21 15:47:35.420954] [NWK_MGR/LSTN] PKTBODY: parentAddr = 0x0000D34C (54092)
[2020-11-21 15:47:35.421074] [NWK_MGR/LSTN] PKTBODY: nwkAddr = 0x0000D34C (54092)
[2020-11-21 15:47:35.427088] < [ZDO/SREQ] **EXT_SEC_APS_REMOVE_REQ** <D34C-00124b000760bb0a> Parent:D34C (SYS:5/TYPE:20/CMD:51) ( 17)::fe 0c 25 51 4c d3 4c d3 0a bb 60 07 00 4b 12 00 f7
[2020-11-21 15:47:35.698590] > [ZDO/SRSP] **EXT_SEC_APS_REMOVE_REQ** ZSuccess (SYS:5/TYPE:60/CMD:51) ( 6)::fe 01 65 51 00 35

**** Other device
[2020-11-21 15:47:37.363760] [NWK_MGR/LSTN] PKTBODY: cmdId = NWK_REMOVE_DEVICE_REQ
[2020-11-21 15:47:37.364139] [NWK_MGR/LSTN] PKTBODY: ieeeAddr = CC:CC:CC:FF:FE:3A:2F:33
[2020-11-21 15:47:37.366035] [NWK_MGR/LSTN] PKTBODY: parentAddr = 0x0000E1B7 (57783)
[2020-11-21 15:47:37.366150] [NWK_MGR/LSTN] PKTBODY: nwkAddr = 0x0000E1B7 (57783)
[2020-11-21 15:47:37.370148] < [ZDO/SREQ] **EXT_SEC_APS_REMOVE_REQ** <E1B7-ccccccfffe3a2f33> Parent:E1B7 (SYS:5/TYPE:20/CMD:51) ( 17)::fe 0c 25 51 b7 e1 b7 e1 33 2f 3a fe ff cc cc cc 93
[2020-11-21 15:47:37.641244] > [ZDO/SRSP] **EXT_SEC_APS_REMOVE_REQ** ZSuccess (SYS:5/TYPE:60/CMD:51) ( 6)::fe 01 65 51 00 35

**** This device removal request did not succeed - the device still appeared in the Device List in the application:
[2020-11-21 15:47:40.412069] [NWK_MGR/LSTN] PKTBODY: cmdId = NWK_REMOVE_DEVICE_REQ
[2020-11-21 15:47:40.412365] [NWK_MGR/LSTN] PKTBODY: ieeeAddr = 70:B3:D5:B1:30:01:01:1E
[2020-11-21 15:47:40.413838] [NWK_MGR/LSTN] PKTBODY: parentAddr = 0x00009424 (37924)
[2020-11-21 15:47:40.413926] [NWK_MGR/LSTN] PKTBODY: nwkAddr = 0x00009424 (37924)
[2020-11-21 15:47:40.421569] < [ZDO/SREQ] **EXT_SEC_APS_REMOVE_REQ** <9424-70b3d5b13001011e> Parent:9424 (SYS:5/TYPE:20/CMD:51) ( 17)::fe 0c 25 51 24 94 24 94 1e 01 01 30 b1 d5 b3 70 f1
[2020-11-21 15:47:40.691802] > [ZDO/SRSP] **EXT_SEC_APS_REMOVE_REQ** ZSuccess (SYS:5/TYPE:60/CMD:51) ( 6)::fe 01 65 51 00 35
[2020-11-21 15:50:09.766092] [NWK_MGR/MAIN] PKTBODY: nwkAddrRsp = 1
[2020-11-21 15:50:12.935236] [NWK_MGR/LSTN] PKTBODY: ieeeAddr = 70:B3:D5:B1:30:01:01:1E

**** At this point the gatway restarted:
[2020-11-21 15:50:13] when we see something missing we will send a SIGUSR2 to pid 551

**** And removing the device "succeeded".
[2020-11-21 15:50:21.401887] [NWK_MGR/LSTN] PKTBODY: cmdId = NWK_REMOVE_DEVICE_REQ
[2020-11-21 15:50:21.402259] [NWK_MGR/LSTN] PKTBODY: ieeeAddr = 70:B3:D5:B1:30:01:01:1E
[2020-11-21 15:50:21.403681] [NWK_MGR/LSTN] PKTBODY: parentAddr = 0x00009424 (37924)
[2020-11-21 15:50:21.403769] [NWK_MGR/LSTN] PKTBODY: nwkAddr = 0x00009424 (37924)
[2020-11-21 15:50:21.411374] < [ZDO/SREQ] **EXT_SEC_APS_REMOVE_REQ** <9424-70b3d5b13001011e> Parent:9424 (SYS:5/TYPE:20/CMD:51) ( 17)::fe 0c 25 51 24 94 24 94 1e 01 01 30 b1 d5 b3 70 f1
[2020-11-21 15:50:21.681819] > [ZDO/SRSP] **EXT_SEC_APS_REMOVE_REQ** ZSuccess (SYS:5/TYPE:60/CMD:51) ( 6)::fe 01 65 51 00 35
[2020-11-21 15:51:52.778861] [NWK_MGR/LSTN] PKTBODY: cmdId = NWK_ZIGBEE_SYSTEM_RESET_REQ
[2020-11-21 15:51:52.778990] [NWK_MGR/LSTN] PKTBODY: mode = HARD_RESET
[2020-11-21 15:51:52.779117] [NWK_MGR/LSTN] MISC1 : NWK_ZIGBEE_SYSTEM_RESET: ResetMode 1
[2020-11-21 15:51:52.780307] [NWK_MGR/LSTN] INFO : preparing to send 6 bytes, subSys 0x11, cmdId 0x00 (SYS_RESET_REQ), pData:
[2020-11-21 15:51:52.780945] [NWK_MGR/LSTN] PKTBODY: cmdID = SYS_RESET_REQ
[2020-11-21 15:51:52.842210] < [SYS/AREQ] **RESET_REQ** (SYS:1/TYPE:40/CMD:00) ( 6)::fe 01 41 00 01 41
[2020-11-21 15:51:54.667997] > [SYS/AREQ] **RESET_IND** EXTRST(1) Protocol 2 ProductID 2 SWVer 2.7.2 (SYS:1/TYPE:40/CMD:80) ( 11)::fe 06 41 80 01 02 02 02 07 02 c1
[2020-11-21 15:52:14] when we see something missing we will send a SIGUSR2 to pid 551


One can see tha the remove request for ZED 70:B3:D5:B1:30:01:01:1E was repeated in the second session, where it disappeared from the Device List.

The sniffer did not capture much during this period, after its reset line had been hit:

[2020-11-21 15:47:08.363092] 32377 â<86><92> Broadcast IEEE 802.15.4 10 Beacon Request^M
[2020-11-21 15:47:08.364902] 32378 â<86><92> IEEE 802.15.4 28 Ack^M
[2020-11-21 15:47:11.538880] < ( 2)::ef 0a
[2020-11-21 15:47:11] done
[2020-11-21 15:47:11] hitting led_reset line, LED dir is /sys/class/leds/evmsk:zigbeeReset:usr2 sleeping 5 seconds after reset... done

That is in itself annoying since from the application's point of view it is difficult to know that the ZNP is not actually functionnal. Any idea to improve on that is welcome.

Also, I think that the INCOMING_MSG's during this period are internal replies of the Coordinator - example:

[2020-11-21 15:47:48.171483] < [AF/SREQ] **DATA_REQUEST_EXT** <0000 EP:01 PAN:BEBE> {SRC EP:0E CLSTR:000A} #0 TXOPT:00() RADIUS:30 (SYS:4/TYPE:20/CMD:02) ( 31)::fe 1a 24 02 02 00 00 be be be be be be 01 be be 0e 0a 00 00 00 1e 06 00 18 09 01 00 00 86 b5
[2020-11-21 15:47:48.192640] > [AF/AREQ] **INCOMING_MSG** <0000/GRP:0000/CLSTR:000A/EP:0E> Seq:0 DstEP:01 SrcMAC:0918 LQI:255 SECURE:0 TIMSTMP:0 DATALEN:6 RADIUS:24 (SYS:4/TYPE:40/CMD:81) ( 31)::fe 1a 44 81 00 00 0a 00 00 00 0e 01 00 ff 00 00 00 00 00 00 06 18 09 01 00 00 86 00 00 00 b5

The examination of the logs also shows that the parentAddr and then nwkAddr in the secApsRemoveReqare are reported as the same. So they are the same as well for EXT_SEC_APS_REMOVE_REQ as well. So it would be logical tha the removal request fail, but they actually return success.

The "Z-Stack Monitor and Test API" documents also says that the status in the EXT_SEC_APS_REMOVE_REQ responses is "Status of removing device from the network" . I think that I have to read that as the status of the removal request, and not the status of the device.


I think there is more to this problem than just fixing the parent in the removal request. I also think that the ZNP code should be improved - using the IEEE Address to remove a device is more precise than the Parent/NWK address.

It appears to me that non of the removal requests succeeded as no Leave requests were issued according to the sniffer.

RestartRequiredToRemoveDevice.zip

  • 0
    Guru 735695 points

    Your sniffer log is large so can you specify which packet numbers or lines to check this issue? If you can elaborate you issue on your sniffer log, that will be better.

  • 0 in reply to YiKai Chen
    Genius 3145 points

    Hi

    The extracts from the log inidcate the time - it is quite simple to find the related position using that.

    My sniffer logs are big because I sniff 24h/24h and logs are split every 1MB or day.

    In my post, I showed:

    [2020-11-21 15:47:08.363092] 32377 â<86><92> Broadcast IEEE 802.15.4 10 Beacon Request
[2020-11-21 15:47:08.364902] 32378 â<86><92> IEEE 802.15.4 28 Ack

    Which is the tshark decode of the sniffer log itself, but with the date reformatted to the general log format so that it can be merged easily.The field after the date is the packet index in the relevant pcap file.  There is only one sniffer file for this case which is zigbee_20201122_133002.pcap .  The keys are in  lastkeys.log & allkeys.log.  Normally 'lastkeys.log' has the best keys.  My tshark script uses 'allkeys.log' though, I try to make sure that 'lastkeys.log' is good.

    Thanks for looking into this.

  • 0
    TI__Guru**** 220087 points

    Hi Mario,

    Thank you for providing this information, I will need more time to look through your post before giving a formal response.

    Regards,
    Ryan

  • 0 in reply to Ryan Brown1
    Genius 3145 points

    I am ok with a bit of delay as long as in the end the issue(s) get(s) solved.

    In the thread regarding the documentation you indicated that Toby made an analysis here .  It indicates that the gateway should not change for this issue for this ZSTACK3.0.2 version.  IMHO, the proposed change should also imply a read of the ZNP version (when the gateway starts) and use that to adapt the way the ZSTACK methods work.

    However, there is at least one issue elsewhere in the gateway as the parentAddr and the nwkAddr are the same to request deletion.

    I further believe that there are other issues related to deletion because of the restarts.

  • 0 in reply to Mario DW
    Genius 3145 points

    FYI, I tried to identify why the device's NWK Address appears as the parent address as well, but this time the EXT_SEC_APS_REMOVE_REQ had the correct parent address. However, still no Leave request sent by the ZNP.

    [2020-11-24 01:22:40.004696] < [ZDO/SREQ] **EXT_SEC_APS_REMOVE_REQ** <D738-00158d00047b8369> Parent:0000        (SYS:5/TYPE:20/CMD:51) ( 17)::fe 0c 25 51 00 00 38 d7 69 83 7b 04 00 8d 15 00 9a
[2020-11-24 01:22:40.016701] > [ZDO/SRSP] **EXT_SEC_APS_REMOVE_REQ**    ZSuccess        (SYS:5/TYPE:60/CMD:51) (  6)::fe 01 65 51 00 35
[2020-11-24 01:22:40.451481] < [AF/SREQ] **DATA_REQUEST_EXT**  <FEC7 EP:0E PAN:BEBE> {SRC EP:01 CLSTR:0702} #140 TXOPT:00() RADIUS:30   (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 c7 fe be be be be be be 0e be be 01 02 07 8c 00 1e 05 00 10 d0 0b 0a 00 58
[2020-11-24 01:22:40.466167] 16890        0x0000 → 0xfec7       ZigBee HA 50 ZCL: Default Response, Seq: 208^M
[2020-11-24 01:22:40.466649] 16891               →              IEEE 802.15.4 5 Ack^M
[2020-11-24 01:22:40.468367] > [AF/SRSP] **DATA_REQUEST_EXT**   ZSuccess        (SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 00 67
[2020-11-24 01:22:40.474404] > [AF/AREQ] **DATA_CONFIRM** ZSuccess EP:01 Seq:140        (SYS:4/TYPE:40/CMD:80) (  8)::fe 03 44 80 00 01 8c 4a
[2020-11-24 01:22:43.596566] 16892        0xfec7 → 0x0000       ZigBee HA 73 ZCL: Report Attributes, Seq: 209^M
[2020-11-24 01:22:43.597063] 16893               →              IEEE 802.15.4 5 Ack^M
[2020-11-24 01:22:43.609958] 16894        0x0000 → 0xfec7       ZigBee 45 APS: Ack, Dst Endpt: 14, Src Endpt: 1^M
[2020-11-24 01:22:43.610439] 16895               →              IEEE 802.15.4 5 Ack^M

  • 0 in reply to Mario DW
    TI__Guru**** 220087 points

    You are correct about Toby's post only applying to newer ZNP solutions, my apologies as it does not apply for your instance.

    nwkMgrDb_RemoveDevice only occurs for processZdoLeaveInd or processNwkRemoveDeviceReq in nwkmgrsrv.c, this does no good if a device is unresponsive.  You could call it in sendNwkRemoveDeviceReq to force completion.  However, the same applies for EXT_SEC_APS_REMOVE_REQ on the ZNP and this needs to stay synced with the gateway.  There is also the matter of child aging on the ZNP, so there are several angles to consider.  Parents should be capable of sending Leave Requests to responsive children, you could check ZDSecMgrDeviceRemove on the ZNP.

    Regards,
    Ryan

  • 0 in reply to Ryan Brown1
    Genius 3145 points

    I should a do a lot of things that IMHO should have been done by TI, but I guess that every TI customer using the gateway has to do that then.  Not your choice, but apparently TI's choice as a corporation.  That's a heavy workload not at all budgetted on my end.


  • 0 in reply to Mario DW
    Genius 3145 points

    The issue is in the gateway that for an unknown reason considers that the device's host address and its parent's short address are the same.

    IMHO this has nothing to with child aging.

    I'll do other tests in the future and modify the gateway code to detect when parent and child are the same.

    The ZNP always returns ZSuccess as well independent of whether the device is present in its internal database or not as requested.

    MT_ZDO_SEC_DEVICE_REMOVE would remove the device based on the IEEE address alone, whereas  MT_ZDO_EXT_SEC_APS_REMOVE_REQ requires parent, child and IEEEEAddress.

    As the issue is in the Gateway, and I do not wish to revisit this question again, I am marking it as "Resolved".  In practice I'll do other tests and resolve it at a future time.