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: Assoc. not reported + Gateway/ZNP gets non responsive - ZIGBEE-LINUX-SENSOR-TO-CLOUD_1.0.1

Part Number: CC2530
Other Parts Discussed in Thread: Z-STACK, CC2538

Several devices that were apparently joined with the ZNP were not reported in the device list.

9747 2020-11-08 18:06:19.582029 00:12:4b:00:10:22:82:77 → 00:0d:6f:00:12:a0:cc:f8 IEEE 802.15.4 27 Association Response, PAN: 0xeb67 Addr: 0x099f
9789 2020-11-08 18:06:36.820021 00:12:4b:00:01:dd:7a:d7 → 00:0d:6f:00:12:19:9e:48 IEEE 802.15.4 27 Association Response, PAN: 0xeb67 Addr: 0x9584
9947 2020-11-08 18:08:53.014896 00:12:4b:00:10:22:82:77 → 00:0d:6f:00:12:a0:cc:f8 IEEE 802.15.4 27 Association Response, PAN: 0xeb67 Addr: 0x099f
9989 2020-11-08 18:09:03.594017 00:12:4b:00:10:22:82:77 → 00:0d:6f:00:12:a0:cc:f8 IEEE 802.15.4 27 Association Response, PAN: 0xeb67 Addr: 0x099f


After checking the logs, I did further attempts to allow association did not seem to set "Association Permit: True".
However, I ended up noticing that I could not longer do onoff requests for the TI SampleLights neither.

In the attached zip files, you'll find the HEX file read back from the CC2530 after the Gateway/ZNP became in responsive as well as difKK.txt listing the differences with the loaded fw.
DbHistoryFull holds the versions of the csv files as the network was extended (it is now automatic), the timestamp in the name of the file should be close (less than a few seconds) to when the CSV file was updated.
pcap files are also included, 'lastkeys.log' has the network key, seriallog.txt.7 holds the serial communication with the CC250 .

Hopefully this helps to identify the cause for these two issues, and hopefully that leads to fixes.

AssocNonReported_ZNP_KO.zip

  • I would recommend against adding devices to the list based on Association Responses and instead wait for the Device Announce that proves the device has received the correct NWK key.  Parsing ZDP_NonResponsive.hex NV items only shows 0x099F existing as a deleted item.  We have discussed ZNP non-responsiveness in some of your other E2E threads.

    Regards,
    Ryan

  • Part Number: CC2530

    In this session, I added a few devices to the network.  As I was experiencing some difficulties, I tried to send new "Permit join" requests, but the gateway ends up replying "TIMEOUTS".

    When checking the serial log, the ZNP does seem quite active but I can not relate this activity to traces in the gateway log.

    So apparently the gaeway is failing in this case and not the ZNP.  The question is: what is causing this?

    These are the logs, including the serial log, the gateway log and the applicadtion log, as well as the last CSV databae.

    ZNP_SerialCom_NotReflectedToApp.zip

  • Dear Ryan

    I created this new thread because it separates the issue related to the announcement of the device to the application from the fact that the gateway is non-responsive.

    This thread is about the gateway not being responsive while there seems to be serial communication.

    The causes for the non-responsiveness of the gateway/znp has different causes - if they appear different, I create a new thread.

    Some causes have already been fixed.  One of them explains why I ran into that issue when doing multiple on/off cycles of the lamps (I fixed the buffer overflow that wrote the nil byte too many), another was related to the Write Attributes Response indicating an error with one of the attributes (another memory buffer overflow), and a few others as well as unidentified ones by applying a more general fix to the zcl structures.
    I still have to fix the issue with the pDeviceInfo thread races (but that is not occurring here). 

    The fact that a device is not making its Device Announcement should not result in the gateway nor the ZNP breaking up.  In fact no external condition should be breaking the gateway (except for a file corruption not due to the gateway).

    The fact that 0x09ff appears as deleted concerns the other thread.  I would like this one to focus on the non-responsiveness that followed.  The serial log and the gateway log may help determine when it happened and hence possibly what caused it.

  • This appears similar to pthread_mutex deadlock/race condition issue noted in the following E2E thread, can you please investigate and confirm?

    Here is a relevant thread for your awareness, although I don't think it is related to the issue at hand.

    Regards,
    Ryan

  • I think neither of these threads are relevant to the current issue, but I am going to add the proposed protection in the first thread(the patch is already applied in the official version). The usage of the cppcheck tool is also excellent - I'll apply that as well.

    I can confirm the general description of the experience with the gateway that was provided in the question.

    The reason why I do not think that this is related to these other threads is my analysis below.

    In summary, the ZNP is active, the Gateway is communicating towards it, but the ZNP seems to act liek a firewall: it is communicating on both sides, but nothing is going through.

    So I believe that for the case described below, the issue is in the ZNP, not in the Gateway.

    Analysis (logs provided further below):

    The first part of the extract below is the onscreen result of a "tail" on the application log, interrupted with CTRL-C and followed with './gw' which executes "./gw_soc_fw_version_query.bin /dev/ttyO1" .  I tried to reproduce the issue found with the previous GW version (mentionned in another thread).  That was the starting point for a more detailed analysis of the logs.

    [2020-11-10T16:31:01] attr_read_confirm_handler:  Status INVALID_PARAMETER.                                                  8:22:44]  Raw=07:00:73:00:08:00:10:03:18:D7:5E                                  8:22:44] attr_read_confirm_handler: Received ZIGBEE_GENERIC_CNF  id=01 >, n_attributelist=1, clstr=0500, attributelist=0011,0000,0000,0000,0000,0000
    [2020-11-18:22:44] attr_read_confirm_handler:  Status INVALID_PARAMETER.                  8:22:45] REQ: addr=< type=0 ieeeaddr=00124B000760BB0A endpointid=01 >, n_attributelist=1, clstr=0500, att8:22:45] sent to GATEWAY: len=24, cmd_id=20, subsystem=19     subsystem=115
    8:22:45]  Raw=18:00:13:14:08:14:12:0D:08:00:11:0A:BB:60:07:00:4B:12:00:28:01:18:8:22:45] Queued command successfully; CBARG = 0
    [2020-11-10T16:31:02] attr_read_confirm_handler: Received ZIGBEE_GENERIC_CNF    8:22:45]  Raw=07:00:73:00:08:00:10:03:18:D8:5E                                                                     root@A0F6FD520323:~# cd tools
    
    
    - zigbeeapp.log 1/15360 0%
    root@A0F6FD520323:~/tools# ./gw
    Using serial port: /dev/ttyO1 @115200
    zbSocProcessRpc: CMD0:64, CMD1:2, not handled
    zbSocProcessRpc: CMD0:64, CMD1:2, not handled
    zbSocProcessRpc: CMD0:65, CMD1:45, not handled
    zbSocProcessRpc: CMD0:64, CMD1:2, not handled
    

    After some while I interrupted this and tried to read from the "socat" virtual port that also connects to /dev/ttyO1:

    root@A0F6FD520323:~/tools# ./gw_soc_fw_version_query.bin /dev/ttyV0
    Using serial port: /dev/ttyV0 @115200
    Received System version.
      Transport Protocol Version: 2
      Product ID: 2
      Software Release: 2.7.2
      Software Revision: 20190523
    
    root@A0F6FD520323:~/tools# date
    Tue Nov 10 18:37:34 UTC 2020
    
    
    

    With the use of socat, I suspect that I can make multiple connections to the serial port as the serial log is continuously logging packs from an to the ZNP before and after this command.  This means that I could inject commands to the ZNP while the gateway is running.

    Also note that the application was not getting back anything before the above command and that command does not appear to impact the behavior of the gateway.

    To see the commands sent by the version tool, I put a tail on the serial log in the background, and executed the readout of the version resulting in:

     01 02 04 a5 00 1e 05 00 00 a5 00 00 00 1e        ..............
    --
    > 2020/11/10 18:43:24.246139  length=6 from=142988 to=142993
     fe 01 64 02 02 65                                ..d..e
    --                                                                                                                                                          ./gw_soc_fw_version_query.bin /dev/ttyV0< 2020/11/10 18:43:24.824823  length=9 from=399670 to=399678
     fe 04 25 45 f4 46 00 05 d3                       ..%E.F...
    --
    > 2020/11/10 18:43:24.834430  length=6 from=142994 to=142999
     fe 01 65 45 c2 e3                                ..eE..
    --
    < 2020/11/10 18:43:25.031501  length=30 from=399679 to=399708
     fe 19 24 02 02 ba da be be be be be be 01 67 eb  ..$...........g.
     01 00 05 a6 00 1e 05 00 00 a6 00 11 00 de        ..............
    --
    > 2020/11/10 18:43:25.043552  length=6 from=143000 to=143005
     fe 01 64 02 02 65                                ..d..e
    --
    root@A0F6FD520323:~/tools# ./gw_soc_fw_version_query.bin /dev/ttyV0
    Using serial port: /dev/ttyV0 @115200
    Received System version.
      Transport Protocol Version: 2
      Product ID: 2
      Software Release: 2.7.2
      Software Revision: 20190523
    root@A0F6FD520323:~/tools# < 2020/11/10 18:43:28.296007  length=1 from=399709 to=399709
     ef                                               .
    --
    < 2020/11/10 18:43:28.298308  length=5 from=399710 to=399714
     fe 00 41 02 43                                   ..A.C
    --
    > 2020/11/10 18:43:28.308228  length=19 from=143006 to=143024
     fe 0e 61 02 02 02 02 07 02 3b 15 34 01 01 00 00  ..a......;.4....
     00 00 70                                         ..p
    --
    < 2020/11/10 18:43:31.285569  length=30 from=399715 to=399744
    
    

    The frame to send the query is 'fe 00 41 02 43' and the reply is indeed the next frame.

    BTW, the printf of the software revision should be inside the if(len > 5) block as software_revision is not set:

                                            if (len > 5)
                                            {
                                                    software_revision = incoming_packet[9] + (incoming_packet[10] << 8) + (incoming_packet[11] << 16) + (incoming_packet[12] << 24);
                                            }
    
                                            printf("  Software Revision: %u\n", software_revision);
    
                                            if (len <= 5)
                                            {
                                                    printf("  (Revision not specified)\n");
                                            }
    

    The analysis of the logs from this point in time onwards show that the ZNP is still communicating, that the packets for attributes reported by an device in the network are not reported on the serial link, and that the ZNP is sending ack messages only, not any of the other commands.

    [2020-11-10 18:43:24.822,814] [Z_STACK/LSTN] INFO   : Receive message...
    [2020-11-10 18:43:24.823,281] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:15
    [2020-11-10 18:43:24.823,546] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:5, cmdID:45, len::4
    [2020-11-10 18:43:24.823,764] [Z_STACK/LSTN] INFO   : preparing to send 4 bytes, subSys 0x05, cmdId 0x45, pData:
    [2020-11-10 18:43:24.823,959] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
    [2020-11-10 18:43:24.826,936] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
    [2020-11-10 18:43:24.827,291] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
    [2020-11-10 18:43:24.827,486] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
    [2020-11-10 18:43:24.827,667] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
    [2020-11-10 18:43:24.828,077] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
    [2020-11-10 18:43:24.830,413] [Z_STACK/LSTN] INFO   : !Done
    
    ***** The serial log corresponds to the gateway
    ***** sending the "4 (payload) bytes" announced above, for subsystem 0x05 (->25),
    ***** and command 0x45, corresponding to 8 bytes in the packet + the checksum.
    ***** The microsecond part of the timestamp is good as well with regards to the above.
    --
    < 2020/11/10 18:43:24.824823  length=9 from=399670 to=399678
     fe 04 25 45 f4 46 00 05 d3                       ..%E.F...
    
    ***** The request to read the version is then perceived by the gateway as an incoming command.
    ***** I suppose that socat is responsible for that.
    --
    > 2020/11/10 18:43:24.834430  length=6 from=142994 to=142999
     fe 01 65 45 c2 e3                                ..eE..
    [2020-11-10 18:43:24.836,839] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x45
    [2020-11-10 18:43:24.837,239] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
    [2020-11-10 18:43:24.837,435] [Z_STACK/READ] INFO   : Client Read: (len 4):
    [...]
    --
    < 2020/11/10 18:43:25.031501  length=30 from=399679 to=399708
     fe 19 24 02 02 ba da be be be be be be 01 67 eb  ..$...........g.
     01 00 05 a6 00 1e 05 00 00 a6 00 11 00 de        ..............
    
    [2020-11-10 18:43:25.027,843] [Z_STACK/LSTN] INFO   : Receive message...
    [2020-11-10 18:43:25.028,672] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:22
    [2020-11-10 18:43:25.029,531] [Z_STACK/LSTN] INFO   : zstackpb Rcvd AF Data Request: addrMode: 2, dstAddr:daba, dep:1, sep:1
    [2020-11-10 18:43:25.029,807] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:4, cmdID:2, len::25
    [2020-11-10 18:43:25.030,039] [Z_STACK/LSTN] INFO   : preparing to send 25 bytes, subSys 0x04, cmdId 0x02, pData:
    [2020-11-10 18:43:25.030,513] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
    [2020-11-10 18:43:25.035,426] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
    [2020-11-10 18:43:25.035,791] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
    [2020-11-10 18:43:25.035,989] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
    [2020-11-10 18:43:25.036,168] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
    ***** "25 bytes" sent by the gateway to the ZNP (+4 header, + 1 checksum). 
    --
    < 2020/11/10 18:43:25.031501  length=30 from=399679 to=399708
     fe 19 24 02 02 ba da be be be be be be 01 67 eb  ..$...........g.
     01 00 05 a6 00 1e 05 00 00 a6 00 11 00 de        ..............
    
    ***** Reception is confirmed by the [ZSTACK/READ]:
    > 2020/11/10 18:43:25.043552  length=6 from=143000 to=143005
     fe 01 64 02 02 65                                ..d..e
    [2020-11-10 18:43:25.051,493] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x64, cmdId 0x02
    [2020-11-10 18:43:25.051,929] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
    [2020-11-10 18:43:25.052,129] [Z_STACK/READ] INFO   : Client Read: (len 4):
    
    

    These traces show that the serial log is in sync with the gateway log, and that the ZNP is replying to the serial requests. Yet there are the INVALID_PARAMETER messages in the application and TIMEOUTS in the gateway log. In fact, the ZNP only sends ACK messages and some zigbee objects are sending packets to the gateway.

    ***** For reference this is the last record sent by the ZNP before the ones follwoing below.
    > 2020/11/10 18:43:33.893096  length=6 from=143037 to=143042
     fe 01 65 45 c2 e3                                ..eE..
    --
    ***** Zigbee GW log:
    [2020-11-10 18:43:33.894,581] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x65, cmdId 0x45
    [2020-11-10 18:43:33.894,857] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
    [2020-11-10 18:43:33.895,008] [Z_STACK/READ] INFO   : Client Read: (len 4):
    
    ***** The sniffer log shows:
     6186 2020-11-10 18:43:36.002655       0x46f4 â~F~R 0x0000       ZigBee HA 53 ZCL: Report Attributes, Seq: 108
     6187 2020-11-10 18:43:36.003145              â~F~R              IEEE 802.15.4 5 Ack
    ***** The device appears in the database:
            00:15:8D:00:04:7B:83:69 , 0x46F4 , 0x00, 0x1037 , 1, 00:12:4B:00:10:22:82:77, 0xBE
    ***** But the serial log only shows communications starting at 18:43:38
    
    ***** Reported in the Gateway log:
    [2020-11-10 18:43:38.513,733] [Z_STACK/LSTN] INFO   : Receive message...
    [2020-11-10 18:43:38.514,198] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:22
    [2020-11-10 18:43:38.514,577] [Z_STACK/LSTN] INFO   : zstackpb Rcvd AF Data Request: addrMode: 2, dstAddr:46f4, dep:1, sep:1
    [2020-11-10 18:43:38.514,817] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:4, cmdID:2, len::25
    [2020-11-10 18:43:38.515,046] [Z_STACK/LSTN] INFO   : preparing to send 25 bytes, subSys 0x04, cmdId 0x02, pData:
    ***** 25 bytes sent:
    < 2020/11/10 18:43:38.516144  length=30 from=399784 to=399813
     fe 19 24 02 02 f4 46 be be be be be be 01 67 eb  ..$...F.......g.
     01 02 04 a9 00 1e 05 00 00 a9 00 00 00 1e        ..............
    --
    [2020-11-10 18:43:38.515,244] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
    [2020-11-10 18:43:38.523,622] [Z_STACK/LSTN] INFO   : Waiting for synchronous response...
    [2020-11-10 18:43:38.523,993] [Z_STACK/LSTN] INFO   : [MUTEX] Lock SRSP Mutex
    [2020-11-10 18:43:38.524,191] [Z_STACK/LSTN] INFO   : [MUTEX] Wait for SRSP Cond signal...
    [2020-11-10 18:43:38.524,370] [Z_STACK/LSTN] INFO   : [MUTEX] Unlock SRSP Mutex
    [2020-11-10 18:43:38.524,795] [Z_STACK/LSTN] INFO   : ...sent 8 bytes to Client
    [2020-11-10 18:43:38.525,079] [Z_STACK/LSTN] INFO   : !Done
    
    
    > 2020/11/10 18:43:38.534702  length=6 from=143043 to=143048
     fe 01 64 02 02 65                                ..d..e
    --
    [2020-11-10 18:43:38.537,441] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x64, cmdId 0x02
    [2020-11-10 18:43:38.537,877] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
    [2020-11-10 18:43:38.538,080] [Z_STACK/READ] INFO   : Client Read: (len 4):
    
    [2020-11-10 18:43:39.185,593] [Z_STACK/LSTN] INFO   : Receive message...
    [2020-11-10 18:43:39.186,019] [Z_STACK/LSTN] INFO   : zstackpb zspbHandlePbCb: subsystemID:31, cmdId:22
    [2020-11-10 18:43:39.186,216] [Z_STACK/LSTN] INFO   : zstackpb Rcvd AF Data Request: addrMode: 2, dstAddr:daba, dep:1, sep:1
    [2020-11-10 18:43:39.186,343] [Z_STACK/LSTN] INFO   : znp_misc sendNPIExpectDefaultStatusZNP: subSys:4, cmdID:2, len::25
    [2020-11-10 18:43:39.186,456] [Z_STACK/LSTN] INFO   : preparing to send 25 bytes, subSys 0x04, cmdId 0x02, pData:
    
    < 2020/11/10 18:43:39.187148  length=30 from=399814 to=399843
     fe 19 24 02 02 ba da be be be be be be 01 67 eb  ..$...........g.
     01 00 05 aa 00 1e 05 00 00 aa 00 11 00 de        ..............
    --
    > 2020/11/10 18:43:39.198683  length=6 from=143049 to=143054
     fe 01 64 02 02 65                                ..d..e
    --
    [2020-11-10 18:43:38.537,441] [Z_STACK/READ] INFO   : Received 1 bytes, subSys 0x64, cmdId 0x02
    [2020-11-10 18:43:38.537,877] [Z_STACK/READ] INFO   : [MUTEX] SRSP Cond signal set
    [2020-11-10 18:43:38.538,080] [Z_STACK/READ] INFO   : Client Read: (len 4):
    
    

    So at least in this case, the issue does not seem to be with the gateway itself that seems to be a lot more stable (no more memory issues), but the issue is with the ZNP.  The ZNP stoppped relaying the requests on its serial interface to the Zigbee RF sie, while still replying to these serial requests.  And the same time the ZNP acknowledges Zigbee packets but not communicate them on the serial interface.

    What could be causing that?  How to fix it?  Or how to get more information to determine the cause?

    Logs:ZNP_PartiallyResponsive.zip

  • Outcome of the 'cppcheck' applied to gateway code:

    [ipclib/server/npi_lnx_ipc.c:1921]: (error) Memory leak: errorStr
                                                    char *errorStr = (char *)malloc(30);
    										Easy fix: char errorStr[30];
    [ipclib/server/npi_lnx_ipc.c:2549]: (error) Memory leak: strBuf
      Obvious one:
                                    strBuf = (char*) malloc(128); // line deleted.
                                    strBuf = pStrBufRoot; 
    [ipclib/server/npi_lnx_ipc.c:410]: (error) Undefined behavior: Variable 'fullStr' is used as parameter and destination in s[n]printf().
      Meant to append to the string...
            sprintf(fullStr, "%s] %s", fullStr, inStr);
      ->  sprintf(fullStr+strlen(fullStr), "] %s", inStr);
    
    
    [ipclib/server/npi_lnx_ipc.c:413]: (error) Undefined behavior: Variable 'fullStr' is used as parameter and destination in s[n]printf().
      Another append that could be merged with the append above:
                 sprintf(fullStr, "%s. Error: %.8X\n", fullStr, npi_ipc_errno);
      ->
                 sprintf(fullStr+strlen(fullStr), ". Error: %.8X\n", npi_ipc_errno);
    
    
    
    Checking ../srvwrapper/api_server.c...
    [../srvwrapper/api_server.c:524]: (error) Memory leak: errorStr
    [../srvwrapper/api_server.c:992]: (error) Undefined behavior: Variable 'fullStr' is used as parameter and destination in s[n]printf().
    [../srvwrapper/api_server.c:995]: (error) Undefined behavior: Variable 'fullStr' is used as parameter and destination in s[n]printf().
    
    
    Checking ../sdb/SimpleDBTxt.c...
    Could happen if (record[0] != SDBT_PENDING_COMMENT_FORMAT_CHARACTER)
    [../sdb/SimpleDBTxt.c:150]: (error) Uninitialized variable: rc
    
    -> Initialised to FALSE.
    
    Checking ../srvepconfig/serverep.c...
    False positive:
    [../srvepconfig/serverep.c:2172]: (error) Memory leak: pNewAttrList
    Complex, but seems false positive.
    [../srvepconfig/serverep.c:2185]: (error) Memory leak: pNewAttrList
    
    
    Checking ../../../../Components/stack/zcl/zcl.c...
    Could be undefined when i=0, initialise to 0
    [../../../../Components/stack/zcl/zcl.c:4834]: (error) Uninitialized variable: j
    
    Checking ../../../../Components/stack/zcl/zcl_green_power.c...
    Not set unless error -> initialise as ZSuccess
    [../../../../Components/stack/zcl/zcl_green_power.c:389]: (error) Uninitialized variable: status
    
    Checking ../serverpb/gatewayp2p.c...
    -> Initialise to FALSE, could be undefined depending on pRsp
    [../serverpb/gatewayp2p.c:161]: (error) Uninitialized variable: isSuccess
    
    Checking aps_groups.c...
    -> Initialise to ZSTATUS_VALUES__ZFailure
    [aps_groups.c:149]: (error) Uninitialized variable: status
    -> Initialise to FALSE
    [aps_groups.c:328]: (error) Uninitialized variable: status
    
    Checking gatewayservices.c...
    
    -> Free the record.
    [gatewayservices.c:805]: (error) Memory leak: pNewAttrListRecord
    
    -> Initialise to 0
    [gatewayservices.c:1116]: (error) Uninitialized variable: clusterMatchCount
    
    Checking gatewaysrvr.c...
    -> Free the record
    [gatewaysrvr.c:7146]: (error) Memory leak: pCfgReportCmd
    
    Checking zcl_port.c...
    -> Init as afStatus_FAILED
    [zcl_port.c:507]: (error) Uninitialized variable: status
    
    
    Checking OtaServer.c...
    -> move fopen after malloc.
    [OtaServer.c:327]: (error) Resource leak: pfile
    -> move fopen after malloc.
    [OtaServer.c:524]: (error) Resource leak: pfile
    
    Checking zcl_port.c...
    -> Init as afStatus_FAILED
    [zcl_port.c:326]: (error) Uninitialized variable: status
    
  • Thank you for that detailed analysis, if the issue involves the ZNP malfunctioning then as with the other threads it will require further debugging of the CC2530 to determine the MCU state.

    Regards,
    Ryan

  • with my new tool, it is now easier to interpret the serial log, we we can see the "version" request and response:

    [2020-11-10 18:43:24.824823] < [ZDO/SREQ] **EXT_ROUTE_DISC**    (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 18:43:24.834430] > [ZDO/SRSP] **EXT_ROUTE_DISC**    (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 18:43:25.031501] < [AF/SREQ] **DATA_REQUEST_EXT**   (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 ba da be be be be be be 01 67 eb 01 00 05 a6 00 1e 05 00 00 a6 00 11 00 de
    [2020-11-10 18:43:25.043552] > [AF/SRSP] **DATA_REQUEST_EXT**   (SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 02 65
    [2020-11-10 18:43:28.296007] <  (  1)::ef
    [2020-11-10 18:43:28.298308] < [SYS/AREQ] **VERSION**   (SYS:1/TYPE:40/CMD:02) (  5)::fe 00 41 02 43
    [2020-11-10 18:43:28.308228] > [SYS/SRSP] **VERSION**   (SYS:1/TYPE:60/CMD:02) ( 19)::fe 0e 61 02 02 02 02 07 02 3b 15 34 01 01 00 00 00 00 70
    [2020-11-10 18:43:31.285569] < [AF/SREQ] **DATA_REQUEST_EXT**   (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 f4 46 be be be be be be 01 67 eb 01 02 04 a7 00 1e 05 00 00 a7 00 00 00 1e
    [2020-11-10 18:43:31.295828] > [AF/SRSP] **DATA_REQUEST_EXT**   (SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 02 65
    [2020-11-10 18:43:32.325084] < [AF/SREQ] **DATA_REQUEST_EXT**   (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 ba da be be be be be be 01 67 eb 01 00 05 a8 00 1e 05 00 00 a8 00 11 00 de
    [2020-11-10 18:43:32.342772] > [AF/SRSP] **DATA_REQUEST_EXT**   (SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 02 65
    [2020-11-10 18:43:33.884446] < [ZDO/SREQ] **EXT_ROUTE_DISC**    (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 ba da 00 05 01
    [2020-11-10 18:43:33.893096] > [ZDO/SRSP] **EXT_ROUTE_DISC**    (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    

    I do not know if these "DATA_REQUEST_EXT" requests are a sign of the ZNP dysfunctionning, but the ZNP is replying (">") to requests from the gateway ("<").

    Earlier in the serial log we rather have this kind of communication:

    [2020-11-09 18:02:31.049356] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 34)::fe 1d 44 81 00 00 00 05 dc 9e 01 01 00 5c 00 c6 77 6c 00 00 09 19 3a 00 20 00 00 ff 00 00 dc 9e 1d b4
    [2020-11-09 18:02:32.470648] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 32)::fe 1b 44 81 00 00 00 05 dc 9e 01 01 00 54 00 1f 89 6c 00 00 07 19 3b 01 0d 00 63 11 dc 9e 1d 33
    [2020-11-09 18:02:32.516165] < [AF/SREQ] **DATA_REQUEST_EXT**   (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 00 00 be be be be be be ff 00 00 01 00 05 62 00 1e 05 00 11 39 00 00 60 f7
    [2020-11-09 18:02:32.530071] > [AF/SRSP] **DATA_REQUEST_EXT**   (SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 00 67
    [2020-11-09 18:02:32.536348] > [AF/AREQ] **DATA_CONFIRM**       (SYS:4/TYPE:40/CMD:80) ( 38)::fe 03 44 80 00 01 62 a4 fe 19 44 81 00 00 00 05 00 00 01 0e 00 ff 00 00 00 00 00 00 05 11 39 00 00 60 00 00 00 64
    [2020-11-09 18:02:32.544601] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 30)::fe 19 44 81 00 00 00 05 00 00 01 01 00 ff 00 00 00 00 00 00 05 11 39 00 00 60 00 00 00 6b
    [2020-11-09 18:02:34.469630] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 32)::fe 1b 44 81 00 00 00 05 dc 9e 01 01 00 41 00 86 a1 6c 00 00 07 19 3c 01 0d 00 63 11 dc 9e 1d 90
    [2020-11-09 18:02:34.514916] < [AF/SREQ] **DATA_REQUEST_EXT**   (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 00 00 be be be be be be ff 00 00 01 00 05 63 00 1e 05 00 11 39 00 00 61 f7
    [2020-11-09 18:02:34.532448] > [AF/SRSP] **DATA_REQUEST_EXT**   (SYS:4/TYPE:60/CMD:02) ( 14)::fe 01 64 02 00 67 fe 03 44 80 00 01 63 a5
    [2020-11-09 18:02:34.537728] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 60)::fe 19 44 81 00 00 00 05 00 00 01 0e 00 ff 00 00 00 00 00 00 05 11 39 00 00 61 00 00 00 65 fe 19 44 81 00 00 00 05 00 00 01 01 00 ff 00 00 00 00 00 00 05 11 39 00 00 61 00 00 00 6a
    [2020-11-09 18:02:36.480387] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 32)::fe 1b 44 81 00 00 00 05 dc 9e 01 01 00 46 00 0f ba 6c 00 00 07 19 3d 01 0d 00 63 11 dc 9e 1d 04
    [2020-11-09 18:02:36.564743] < [AF/SREQ] **DATA_REQUEST_EXT**   (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 00 00 be be be be be be ff 00 00 01 00 05 64 00 1e 05 00 11 39 00 00 62 f3
    [2020-11-09 18:02:36.580941] > [AF/SRSP] **DATA_REQUEST_EXT**   (SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 00 67
    [2020-11-09 18:02:36.587918] > [AF/AREQ] **DATA_CONFIRM**       (SYS:4/TYPE:40/CMD:80) ( 38)::fe 03 44 80 00 01 64 a2 fe 19 44 81 00 00 00 05 00 00 01 0e 00 ff 00 00 00 00 00 00 05 11 39 00 00 62 00 00 00 66
    [2020-11-09 18:02:36.614779] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 30)::fe 19 44 81 00 00 00 05 00 00 01 01 00 ff 00 00 00 00 00 00 05 11 39 00 00 62 00 00 00 69
    [2020-11-09 18:07:38.882274] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 32)::fe 1b 44 81 00 00 01 00 dc 9e 01 01 00 44 00 73 25 7b 00 00 07 18 3e 0a 21 00 20 c8 dc 9e 1d 49
    

    So a fair amount of "INCOMING_MSG"  with "DATA_REQUEST_EXT" and "DATA_CONFIRM" exchanges as well.

    The last incoming message before [2020-11-10 18:43:24.824823]  is:

    [2020-11-10 00:32:58.761572] > [AF/AREQ] **INCOMING_MSG**       (SYS:4/TYPE:40/CMD:81) ( 32)::fe 1b 44 81 00 00 01 00 dc 9e 01 01 00 5e 00 27 93 cd 00 00 07 18 37 0a 21 00 20 c8 dc 9e 1d 0e

    What do you conclude of this?seriallog.log.15.zip

  • Hey le_top,

    Monitor and Test API packets are formatted as such:

    SOF | LEN | CMD0 | CMD1 | DATA | FCS

    Where SOF is 0xFE and LEN contains the number of DATA bits.  In all of the DATA_REQUEST_EXT ZNP responses it can be observed that DATA is 0x02 which is the INVALID_PARAMETER status.  There can be multiple causes of this in Z-Stack.  The EXT_ROUTE_DISC response with DATA of 0xC2 which is a ZNwkInvalidRequest.

    Regards,
    Ryan

  • Hi Ryan

    I'll extend my MT packet decoder because my end goal is to fix what is causing this and other unexpected behaviors.

    I guess that the next step is that I examine and debug the ZNP?!

    Kind regards

    Mario

  • I added the RSP decoder to my script - hopefully the decoding is correct.
    I attached an updated log with this extra decoding.

    Some observations:

    **** BufferFull - happens more tha once, not sure if that is the issue.  What buffer to increase?
    [2020-11-10 00:29:08.204208] > [AF/SRSP] **DATA_REQUEST_EXT** 	ZBufferFull	(SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 11 76 
    [2020-11-10 00:29:10.395330] < [ZDO/SREQ] **EXT_ROUTE_DISC** 	(SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3 
    [2020-11-10 00:29:10.403494] > [ZDO/SRSP] **EXT_ROUTE_DISC** 	ZSuccess	(SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21 
    [2020-11-10 00:29:14.962793] < [AF/SREQ] **DATA_REQUEST_EXT** 	(SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 f4 46 be be be be be be 01 67 eb 01 02 04 e8 00 1e 05 00 00 e8 00 00 00 1e 
    [2020-11-10 00:29:14.973958] > [AF/SRSP] **DATA_REQUEST_EXT** 	ZBufferFull	(SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 11 76 
    [2020-11-10 00:29:16.867424] > [AF/AREQ] **DATA_CONFIRM** 	(SYS:4/TYPE:40/CMD:80) (  9)::fe 03 44 80 f0 01 e0 d6 fe 
    [2020-11-10 00:29:16.885084] >  ( 47)::03 44 80 f0 01 e1 d7 fe 03 44 80 f0 01 e2 d4 fe 03 44 80 f0 01 e3 d5 fe 03 44 80 f0 01 e4 d2 fe 03 44 80 f0 01 e5 d3 fe 03 44 80 f0 01 e6 d0 
    **** TableFull - from then onwards it all goes wrong apparently:
    [2020-11-10 00:34:57.283276] > [SYS/AREQ] **RESET_IND** 	(SYS:1/TYPE:40/CMD:80) ( 11)::fe 06 41 80 01 02 02 02 07 02 c1 
    [2020-11-10 00:35:01.796525] < [ZDO/SREQ] **EXT_ROUTE_DISC** 	(SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3 
    [2020-11-10 00:35:01.804999] > [ZDO/SRSP] **EXT_ROUTE_DISC** 	ZNwkTableFull	(SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c7 e6 
    [2020-11-10 00:35:01.811069] < [AF/SREQ] **DATA_REQUEST_EXT** 	(SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 f4 46 be be be be be be 01 67 eb 01 02 04 16 00 1e 05 00 00 16 00 00 00 1e 
    [2020-11-10 00:35:01.821736] > [AF/SRSP] **DATA_REQUEST_EXT** 	ZInvalidParameter	(SYS:4/TYPE:60/CMD:02) (  6)::fe 01 64 02 02 65 
    [2020-11-10 00:35:01.827691] < [AF/SREQ] **DATA_REQUEST_EXT** 	(SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 f4 46 be be be be be be 01 67 eb 01 02 04 17 00 1e 05 00 00 17 00 00 00 1e 
    

    Also, I am not sure how to decode these:

    [2020-11-10 14:10:45.170186] > [ZDO/SRSP] **EXT_NWK_INFO**     UNK (254)       (SYS:5/TYPE:60/CMD:50) ( 29)::fe 18 65 50 fe ff 00 fe ff fe ff 77 82 22 10 00 4b 12 00 00 00 00 00 00 00 00 00 00 b2
    [2020-11-10 14:36:28.740602] > [ZDO/SRSP] **EXT_NWK_INFO**     UNK (254)       (SYS:5/TYPE:60/CMD:50) ( 29)::fe 18 65 50 fe ff 00 fe ff fe ff 77 82 22 10 00 4b 12 00 00 00 00 00 00 00 00 00 00 b2
    

    Does this correspond to the next ZSTACK CODE, and what does it mean?:

    Components/stack/zdo/ZDNwkMgr.c:    ZDP_MgmtNwkUpdateReq( &dstAddr, channelMask, 0xfe, 0, _NIB.nwkUpdateId, 0 );

    Hopefully that gives some good hints about the cause.

    seriallog_log_15.zip

  • ZBufferFull corresponds to the data buffer queue maximum values in nwk_globals.c of the ZNP, NWK_MAX_DATABUFS_*.  In the Known Issues E2E post it is recommended to double these values to handle instances involving large amounts of network traffic.

    The ZDO_EXT_NWK_INFO command sent by the gateway is being responded to with network information stored in the ZNP's NIB (MT_ZdoExtNwkInfo).  ZDO_MGMT_NWK_UPDATE_REQ has a Cmd0 of 0x25 and a Cmd1 of 0x37, a combination of which does not seem to appear in the log.

    Regards,
    Ryan

  • Hi Ryan

    These are usefull contributions, thanks.

    Do you agree that the SRSP has a status code in the first byte and that this status code ix 0xfe in the following synchronous transaction:

    [2020-11-10 14:10:45.161164] < [ZDO/SREQ] **EXT_NWK_INFO**      (SYS:5/TYPE:20/CMD:50) (  5)::fe 00 25 50 75
    [2020-11-10 14:10:45.170186] > [ZDO/SRSP] **EXT_NWK_INFO**      UNK (254)       (SYS:5/TYPE:60/CMD:50) ( 29)::fe 18 65 50 fe ff 00 fe ff fe ff 77 82 22 10 00 4b 12 00 00 00 00 00 00 00 00 00 00 b2
    

    I did a grep on all my serial logs and the sequence "25 37" never appears as a command.  Is a change required in the gateway or application to get ZDO_MGMT_NWK_UPDATE_REQ  ?

    These useful observations do not allow us to understand why we get "ZNwkTableFull", the cause of which may explain why the system is dysfunctioning .  Any idea about that?

    Note: the list of known fixes is for the CC2538, while this GW is running on the CC2530.

  • Upon examination, the following sequence

    [2020-11-10 00:35:01.796525] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:01.804999] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkTableFull   (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c7 e6

    is the result of a call to NLME_RouteDiscoveryRequest which is part of the API for which the source code is not available.
    I can't determine why the ZNwkTable is full, how to avoid it, how to empty it. 

    On earlier occasions the response is ZSuccess

    [2020-11-09 01:13:41.970905] < [ZDO/SREQ] **EXT_ROUTE_DISC** <9EDC>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 dc 9e 00 05 23
    [2020-11-09 01:13:41.979842] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21

  • ZDO_MGMT_NWKUPDATE_REQUEST & MT_ZDO_MGMT would have to be defined by the ZNP firmware (appears to be by default but I'm not sure for your instance), but this matters little since it never appears to be used by the gateway.

    ZNwkTableFull implies either the maximum routing table entries has been surpassed or you are not cleaning up the associated device entries in the address table.  From NLME_RouteDiscoveryRequest usage it occurs if RTG_UpdateRtDiscEntry (adds an entry to the RREQ table if there is no matching entry or if there is a matching entry but with a higher cost) is not successful.  Other return values are RTG_HIGHER_COST or RTG_TBL_FULL.

    Regards,
    Ryan

  • If MT_ZDO_MGMT is defined or ZDO_API_ADVANCED then ZDO_MGMT_NWKUPDATE_REQUEST  is defined.

    We have in znp.cfg:

    ./Projects/zstack/ZNP/Source/znp.cfg:-DMT_ZDO_MGMT

    It appears allover in the listings of the compilation that I made using the patches provived by Koenkk which correspond pretty much to the optimisations suggested by one of TI's application notes.

    ./ZNP/CC253x/CC2530-ZNP-without-SBL/List/MT_AF.lst:#        -DMT_SAPI_CB_FUNC -DMT_ZDO_CB_FUNC -DMT_ZDO_FUNC -DMT_ZDO_MGMT
    ./ZNP/CC253x/CC2530-ZNP-without-SBL/List/MT_AF.s51://        -DMT_ZDO_MGMT -DMT_ZDO_EXTENSIONS -DMT_GP_CB_FUNC -DMT_APP_FUNC

    So I trust that MT_ZDO_MGMT is active, and hence also ZDO_MGMT_NWKUPDATE_REQUEST because that is inside an "#if define .MT_ZDO_MGMT ... #define ZDO_MGMT_NWK_UPDATE_REQUEST".

    Should I worry about trying to activate this somehow from the gateway?

    P.S.: I trust that you examine my previous responses for pending subquestions or items.

  • The NwkTableFull occurs also after requesting to do a network discovery for a device for which the discovery was executed before:

    2020-11-10 00:32:34.202522] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:32:34.209849] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:32:42.001864] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:32:42.009132] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:32:48.563411] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:32:48.570748] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:32:56.113541] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:32:56.121790] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:33:01.931921] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:33:01.939310] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:33:09.221504] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:33:09.228720] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:33:15.761417] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:33:15.768865] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:33:25.727216] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:33:37.734156] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:33:49.745423] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:34:13.756317] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:34:25.758111] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:34:49.794442] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:01.796525] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:01.804999] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkTableFull   (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c7 e6
    [2020-11-10 00:35:01.883444] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:01.892225] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:35:01.914123] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:01.921427] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZSuccess        (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 00 21
    [2020-11-10 00:35:12.687809] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:12.697755] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 00:35:27.511585] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:27.520155] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 00:35:40.067431] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:40.078668] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 00:35:55.134190] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:35:55.142829] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 00:36:09.691833] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:36:09.700427] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 00:36:23.234874] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:36:23.243537] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 00:36:37.549710] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 00:36:37.559164] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    

    Even while there are plenty of ZNwkInvalidRequest responses, I can still find a spurious NwkTableFull reply - strange.

    [2020-11-10 02:34:02.841932] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 02:34:02.850471] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 02:34:16.135793] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 02:34:16.144443] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 02:34:30.458785] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 02:34:30.468076] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkTableFull   (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c7 e6
    [2020-11-10 02:34:43.781603] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 02:34:43.790406] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    [2020-11-10 02:34:58.341876] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4>  NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) (  9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-10 02:34:58.351644] > [ZDO/SRSP] **EXT_ROUTE_DISC**    ZNwkInvalidRequest      (SYS:5/TYPE:60/CMD:45) (  6)::fe 01 65 45 c2 e3
    

    So this repetition is harmfull and should be cleaned up by the gateway?

    I can't find zdoMgmtNwkUpdateReq or ZDO_MGMT_NWK_UPDATE_REQ being used outside the ZLSZNP - it doesn seep to be in the sample app.

    I attach an updated combined log -

    8255.AssocNonReported_ZNP_KO.zip

  • I agree that ZDO_MGMT_NWK_UPDATE_REQUEST could be defined but argue that ZDO_MGMT_NWK_UPDATE_REQ never appears to be used.  I see no reason to use this functionality for the gateway.

    I advise against extraneous ZDO_EXT_ROUTE_DISC, I'm not understanding why so many duplicates are sent consecutively to the same destination address but it is a concern.

    I apologize for the oversight of any remaining items, they will need to be raised again as I am not aware of pending questions.

    Regards,
    Ryan

  • **** The Device that we also look at further below has already been notified from the ZNP with this serial communication:
    [2020-11-08 17:08:53.885446] > [ZDO/AREQ] **TC_DEVICE_IND** <099F-000d6f0012a0ccf8> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca 9f 09 f8 cc a0 12 00 6f 0d 00 00 00 f1
    
    **** In the combined log, the messages are pretty much synchronised.
    **** The request to read attributes below:
    [2020-11-08 17:08:54.225,914] [GATEWAY/LSTN] PKTTYPE: [ GATEWAY<<<<<<<<<<<CON006] GwReadDeviceAttributeReq
    [2020-11-08 17:08:54.226,025] [GATEWAY/LSTN] PKTBODY: cmdId = GW_READ_DEVICE_ATTRIBUTE_REQ
    [2020-11-08 17:08:54.226,103] [GATEWAY/LSTN] PKTBODY: dstAddress :
    [2020-11-08 17:08:54.226,170] [GATEWAY/LSTN] PKTBODY: addressType = UNICAST
    [2020-11-08 17:08:54.226,246] [GATEWAY/LSTN] PKTBODY: ieeeAddr = 70:B3:D5:B1:30:01:01:1E
    [2020-11-08 17:08:54.226,320] [GATEWAY/LSTN] PKTBODY: endpointId = 0x0000000E (14)
    [2020-11-08 17:08:54.226,393] [GATEWAY/LSTN] PKTBODY: clusterId = 0x00000B04 (2820)
    [2020-11-08 17:08:54.226,457] [GATEWAY/LSTN] PKTBODY: attributeList :
    [2020-11-08 17:08:54.226,519] [GATEWAY/LSTN] PKTBODY: [000] = 0x0000050F (1295)
    [2020-11-08 17:08:54.226,586] [GATEWAY/LSTN] PKTBODY: isServerToClient = 0x00000000 (0)
    
    **** is sent by the Z_STACK server:
    [2020-11-08 17:08:54.291,142] [Z_STACK/LSTN] INFO : zstackpb Rcvd AF Data Request: addrMode: 2, dstAddr:92a4, dep:14, sep:1
    [2020-11-08 17:08:54.291,271] [Z_STACK/LSTN] INFO : znp_misc sendNPIExpectDefaultStatusZNP: subSys:4, cmdID:2, len::25
    [2020-11-08 17:08:54.291,392] [Z_STACK/LSTN] INFO : preparing to send 25 bytes, subSys 0x04, cmdId 0x02, pData:
    [2020-11-08 17:08:54.291,494] [Z_STACK/LSTN] INFO : [MUTEX] Lock SRSP Transaction Mutex
    [2020-11-08 17:08:54.292076] < [AF/SREQ] **DATA_REQUEST_EXT** <92A4 EP:0E PAN:EB67> {SRC EP:01 CLSTR:0B04} #109 TXOPT:00() RADIUS:30 (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 a4 92 be be be be be be 0e 67 eb 01 04 0b 6d 00 1e 05 00 00 6d 00 0f 05 96
    [2020-11-08 17:08:54.308283] > [AF/SRSP] **DATA_REQUEST_EXT** ZSuccess (SYS:4/TYPE:60/CMD:02) ( 6)::fe 01 64 02 00 67
    
    **** The RF sniffer saw the packet in the air:
    [2020-11-08 17:08:54.313085] 9967 0x0000 → 0x92a4 ZigBee HA 50 ZCL: Read Attributes, Seq: 109^M
    [2020-11-08 17:08:54.313587] 9968 → IEEE 802.15.4 5 Ack^M
    
    
    **** The next request to send a packet with Sequence/transID 110 is sent to the ZNP:
    [2020-11-08 17:09:01.038925] < [AF/SREQ] **DATA_REQUEST_EXT** <46F4 EP:01 PAN:EB67> {SRC EP:01 CLSTR:0402} #110 TXOPT:00() RADIUS:30 (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 f4 46 be be be be be be 01 67 eb 01 02 04 6e 00 1e 05 00 00 6e 00 02 00 1c
    [2020-11-08 17:09:01.052265] > [AF/SRSP] **DATA_REQUEST_EXT** ZSuccess (SYS:4/TYPE:60/CMD:02) ( 6)::fe 01 64 02 00 67
    [...]
    [2020-11-08 17:09:01.055,791] [GATEWAY/LSTN] INFO : (GW posted) cmdId: 20, zclTransId 110
    
    **** The sniffer will not see that packet being sent...
    
    
    **** Transaction/Sequence request 111 is also sent to the ZNP:
    [2020-11-08 17:09:01.310844] < [AF/SREQ] **DATA_REQUEST_EXT** <92A4 EP:0E PAN:EB67> {SRC EP:01 CLSTR:0B04} #111 TXOPT:00() RADIUS:30 (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 a4 92 be be be be be be 0e 67 eb 01 04 0b 6f 00 1e 05 00 00 6f 00 0f 05 96
    
    **** And the sniffer observes this request sequence 111:
    [2020-11-08 17:09:01.332365] 9973 0x0000 → 0x92a4 ZigBee HA 50 ZCL: Read Attributes, Seq: 111^M
    [2020-11-08 17:09:01.332753] 9974 → IEEE 802.15.4 5 Ack^M
    
    **** Confirmed by the ZNP:
    [2020-11-08 17:09:01.334412] > [AF/AREQ] **DATA_CONFIRM** ZSuccess EP:01 Seq:111 (SYS:4/TYPE:40/CMD:80) ( 8)::fe 03 44 80 00 01 6f a9
    
    [2020-11-08 17:09:02.428628] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4> NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) ( 9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-08 17:09:02.436240] > [ZDO/SRSP] **EXT_ROUTE_DISC** ZSuccess (SYS:5/TYPE:60/CMD:45) ( 6)::fe 01 65 45 00 21
    
    
    **** The device that weill be 0x099f makes its association request:
    [2020-11-08 17:09:03.397192] 9985 00:0d:6f:00:12:a0:cc:f8 → 0x0000 IEEE 802.15.4 21 Association Request, RFD^M
    
    **** The coordinator assigns 0x099F:
    [2020-11-08 17:09:03.591698] 9987 00:0d:6f:00:12:a0:cc:f8 → 0x0000 IEEE 802.15.4 18 Data Request^M
    [2020-11-08 17:09:03.592192] 9988 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.594017] 9989 00:12:4b:00:10:22:82:77 → 00:0d:6f:00:12:a0:cc:f8 IEEE 802.15.4 27 Association Response, PAN: 0xeb67 Addr: 0x099f^M
    [2020-11-08 17:09:03.594292] 9990 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.600827] 9991 0x099f → 0x0000 IEEE 802.15.4 12 Data Request^M
    [2020-11-08 17:09:03.601317] 9992 → IEEE 802.15.4 5 Ack^M
    ****
    **** The transaction is initiated by the ZNP, not by by the gateway. 
    **** It is the last one sent by the ZNP (except for acks) and it could not be decoded
    **** (which could be a sign of an issue in the ZNP).
    ****
    [2020-11-08 17:09:03.608192] 9993 0x0000 → 0x099f IEEE 802.15.4 108 Reserved, Dst: 0x099f, Src: 0x0000, Bad FCS^M
    [2020-11-08 17:09:03.608259] 9994 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.630067] 9995 0x099f → 0x0000 ZigBee HA 110 ZCL: Report Attributes, Seq: 24^M
    [2020-11-08 17:09:03.630197] 9996 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.634335] 9997 0x099f → 0x0000 ZigBee ZDP 54 Match Descriptor Request, Nwk Addr: 0x0000, Profile: 0x0104^M
    [2020-11-08 17:09:03.634675] 9998 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.639100] 9999 0x099f → Broadcast ZigBee ZDP 65 Device Announcement, Nwk Addr: 0x099f, Ext Addr: Ember_00:12:a0:cc:f8^M
    [2020-11-08 17:09:03.639224] 10000 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.643436] 10001 0x099f → Broadcast ZigBee ZDP 65 Device Announcement, Nwk Addr: 0x099f, Ext Addr: Ember_00:12:a0:cc:f8^M
    [2020-11-08 17:09:03.643501] 10002 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.647699] 10003 0x099f → 0x0000 ZigBee HA 62 ZCL IAS Zone: Zone Status Change Notification, Seq: 25^M
    [2020-11-08 17:09:03.648047] 10004 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.653558] 10005 0x099f → 0x0000 ZigBee HA 64 ZCL: Report Attributes, Seq: 26^M
    [2020-11-08 17:09:03.653624] 10006 → IEEE 802.15.4 5 Ack^M
    [2020-11-08 17:09:03.657708] 10007 → IEEE 802.15.4 5 Ack^M
    
    **** The data sent on the serial link is unintelligeable (the packet before that is valid):
    [2020-11-08 17:09:03.679590] > ( 29)::85 18 82 85 19 83 e4 12 fa f1 22 f0 aa 18 ab 19 79 52 12 3a c4 22 c0 82 c0 83 74 fe 12
    [2020-11-08 17:09:03.687083] > ( 39)::12 22 70 12 ee 4e 02 d8 cd 12 45 5c 8a 0c 8b 0d ae 0c af 0d ea 4f 22 12 ee 44 22 ee 24 0e f5 82 e4 3f f5 83 22 12 e7
    
    **** To make sure, I checked the raw serial trace:
    > 2020/11/08 17:09:03.679590 length=29 from=73812 to=73840
    85 18 82 85 19 83 e4 12 fa f1 22 f0 aa 18 ab 19 ..........".....
    79 52 12 3a c4 22 c0 82 c0 83 74 fe 12 yR.:."....t..
    --
    > 2020/11/08 17:09:03.687083 length=39 from=73841 to=73879
    12 22 70 12 ee 4e 02 d8 cd 12 45 5c 8a 0c 8b 0d ."p..N....E\....
    ae 0c af 0d ea 4f 22 12 ee 44 22 ee 24 0e f5 82 .....O"..D".$...
    e4 3f f5 83 22 12 e7 .?.."..
    --
    
    
    ****
    **** And that is the last thing that the ZNP sent using the serial link up to its reset where it immediately replied that the NwkTable is full:
    
    [2020-11-08 17:37:35.168324] > ( 1)::00
    [2020-11-08 17:37:36.944052] > [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-08 17:37:38.916449] < [ZDO/SREQ] **EXT_ROUTE_DISC** <46F4> NOOPTIONS RADIUS 5 (SYS:5/TYPE:20/CMD:45) ( 9)::fe 04 25 45 f4 46 00 05 d3
    [2020-11-08 17:37:38.924501] > [ZDO/SRSP] **EXT_ROUTE_DISC** ZNwkTableFull (SYS:5/TYPE:60/CMD:45) ( 6)::fe 01 65 45 c7 e6
    [2020-11-08 17:37:38.931375] < [AF/SREQ] **DATA_REQUEST_EXT** <92A4 EP:0E PAN:EB67> {SRC EP:01 CLSTR:0B04} #32 TXOPT:00() RADIUS:30 (SYS:4/TYPE:20/CMD:02) ( 30)::fe 19 24 02 02 a4 92 be be be be be be 0e 67 eb 01 04 0b 20 00 1e 05 00 00 20 00 0f 05 96

    So clearly, the ZNP failed for some reason, and this state was maintained through the reset.

    Note that is this is only one of the issues for this Question/

    Several associations were unsuccessfull prior to the abov - they can be found in the logs (attached again, with more complete decoding, and more logs: 5047.AssocNonReported_ZNP_KO.zip):

    [2020-11-08 15:26:33.721811] > [ZDO/AREQ] **TC_DEVICE_IND** <9A9B-70b3d5b13001011e> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca 9b 9a 1e 01 01 30 b1 d5 b3 70 00 00 0b
    [2020-11-08 15:27:39.934330] > [ZDO/AREQ] **TC_DEVICE_IND** <9A9B-70b3d5b13001011e> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca 9b 9a 1e 01 01 30 b1 d5 b3 70 00 00 0b
    [2020-11-08 15:34:23.765599] > [ZDO/AREQ] **TC_DEVICE_IND** <E58D-000d6f000e8a756f> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca 8d e5 6f 75 8a 0e 00 6f 0d 00 00 00 17
    [2020-11-08 15:35:24.192067] > [ZDO/AREQ] **TC_DEVICE_IND** <E58D-000d6f000e8a756f> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca 8d e5 6f 75 8a 0e 00 6f 0d 00 00 00 17
    [2020-11-08 16:34:05.163424] > [ZDO/AREQ] **TC_DEVICE_IND** <E6A4-00124b0001dd7ad7> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca a4 e6 d7 7a dd 01 00 4b 12 00 00 00 e9
    [2020-11-08 16:47:12.424246] > [ZDO/AREQ] **TC_DEVICE_IND** <4EE6-00124b0001dd7872> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca e6 4e 72 78 dd 01 00 4b 12 00 00 00 a4
    [2020-11-08 16:47:25.622224] > [ZDO/AREQ] **TC_DEVICE_IND** <3EE5-00124b0001dd7872> Parent:E6A4 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca e5 3e 72 78 dd 01 00 4b 12 00 a4 e6 95
    [2020-11-08 16:47:31.439857] > [ZDO/AREQ] **TC_DEVICE_IND** <92A4-70b3d5b13001011e> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca a4 92 1e 01 01 30 b1 d5 b3 70 00 00 3c
    [2020-11-08 16:47:39.180928] > [ZDO/AREQ] **TC_DEVICE_IND** <3F73-00124b0001dd7872> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca 73 3f 72 78 dd 01 00 4b 12 00 00 00 40
    [2020-11-08 17:06:20.180735] > [ZDO/AREQ] **TC_DEVICE_IND** <099F-000d6f0012a0ccf8> Parent:0000 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca 9f 09 f8 cc a0 12 00 6f 0d 00 00 00 f1
    [2020-11-08 17:06:38.161025] > [ZDO/AREQ] **TC_DEVICE_IND** <9584-000d6f0012199e48> Parent:E6A4 (SYS:5/TYPE:40/CMD:CA) ( 17)::fe 0c 45 ca 84 95 48 9e 19 12 00 6f 0d 00 a4 e6 6f

  • The "ZNwkTableFull" issue has nothing to do with any of the reasons mentioned in this thread, but it is a standard function of the ZNP and a limitation of the gateway.  I'll fix that in the gateway.

    The unreported associations are still an issue for my application, so this is why this question remains open.

  • I re-examined the logs, it seems complicated to extract more information from them.

    I suppose that the association issue will be better documented in a next test case.

    the apparent ZNP crash has already been documented in later Questions.

    The other cause for lack of responsiveness from the ZNP has been identified and countered in updates I mad to the gateway.

    Therefore, I am labeling this as "Resolved" to indicate that no further handling of this question is requested.