• State Resolved
  • Locked Locked
  • Replies 1 reply
  • Subscribers 55 subscribers
  • Views 196 views
  • Users 0 members are here
Support feedback
Options
Options
Similar topics

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.

Original question:

CC1352P: SRSP Cond Wait timed out

CC2530: SRSP delay - multiples of 1 second - ZIGBEE-LINUX-SENSOR-TO-CLOUD_1.0.1

Mario DW
Genius 3145 points
Part Number: CC2530

I now also ran into the SRSP delay issue.
In order to know how much the delay should be I decided to measure it:

      while ((result == 0) && (pInstance->numOfReceivedSRSPbytes == 0))
#define SRSP_TIMEOUT_S 5

  expirytime.tv_sec = curtime.tv_sec + SRSP_TIMEOUT_S;
  expirytime.tv_nsec = curtime.tv_usec * 1000;

      {
        result = pthread_cond_timedwait( &pInstance->clientSREQcond, &pInstance->clientSREQmutex, &expirytime );
      }
      struct timeval pasttime;
      gettimeofday( &pasttime, NULL );

      // [...]
      if ( rspMsg !=NULL)
      {
        if(pasttime.tv_usec>curtime.tv_usec) {
            pasttime.tv_usec-=curtime.tv_usec;
            pasttime.tv_sec-=curtime.tv_sec;
        } else {
            pasttime.tv_usec+=1000000L;
            pasttime.tv_usec-=curtime.tv_usec;
            pasttime.tv_sec+=1;
            pasttime.tv_sec-=curtime.tv_sec;
        }
        uiPrintfEx( trWARNING, "SRSP Delay %u.%06u\n", pasttime.tv_sec, pasttime.tv_usec);
      // [...]

I was surprised by the results:

[2020-11-26 23:18:55.081673] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.000276
[2020-11-26 23:18:55.081673] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.000276
[2020-11-26 23:18:57.082400] [NWK_MGR/MAIN] WARNING: SRSP Delay 2.000639
[2020-11-26 23:18:57.097178] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.014666
[2020-11-26 23:19:20.103357] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.000166
[2020-11-26 23:19:22.104502] [NWK_MGR/MAIN] WARNING: SRSP Delay 2.001054
[2020-11-26 23:19:22.117378] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.012757
[2020-11-26 23:21:32.914494] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.000143
[2020-11-26 23:21:34.915530] [NWK_MGR/MAIN] WARNING: SRSP Delay 2.000960
[2020-11-26 23:21:34.926728] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.011098
[2020-11-26 23:21:41.843945] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.000314
[2020-11-26 23:21:43.845172] [NWK_MGR/MAIN] WARNING: SRSP Delay 2.001163
[2020-11-26 23:21:43.861269] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.015734
[2020-11-26 23:21:58.468563] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.000271
[2020-11-26 23:22:00.470616] [NWK_MGR/MAIN] WARNING: SRSP Delay 2.001966
[2020-11-26 23:22:00.482656] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.011940
[2020-11-26 23:22:16.429393] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.000366
[2020-11-26 23:22:18.430701] [NWK_MGR/MAIN] WARNING: SRSP Delay 2.001199
[2020-11-26 23:22:18.444897] [NWK_MGR/MAIN] WARNING: SRSP Delay 0.014043
[2020-11-26 23:18:57.082400] [NWK_MGR/MAIN] WARNING: SRSP Delay 2.000639

They are all minimum 1 second and the pthread_cond_wait seems to expire quickly for small values, but on multiples of full seconds later on (the set limit is 5, and the delays observed for the SRSP is 2 seconds).

This can also be checked using the following SRSP transaction:

[2020-11-26 23:51:39.672192] [NWK_MGR/MAIN] MISC1  : NwkMgr sendSysNwkInfoReadReqAndSetTxPower:
[2020-11-26 23:51:39.672196] [NWK_MGR/MAIN] INFO   : preparing to send 2 bytes, subSys 0x11, cmdId 0x08 (SYS_NWK_INFO_READ_REQ), pData:
[2020-11-26 23:51:39.672200] [NWK_MGR/MAIN] INFO   : [MUTEX] Lock SRSP Transaction Mutex
[2020-11-26 23:51:41.672746] [NWK_MGR/READ] INFO   : [MUTEX] SRSP Cond signal set
[2020-11-26 23:51:41.672750] [NWK_MGR/READ] INFO   : Client Read: (len 53):
[2020-11-26 23:51:41.672771] [NWK_MGR/MAIN] WARNING: SRSP Delay 2.000490

My setup for this observation is the following:

- NPI server running on embedded platform on AM335x;
- Other gateway servers running in Ubuntu 16.04 VM (VirtualBox), running on Win10.

I havent measured it yet in the pure embedded setup, but there may be some setting to optimise this delay .

  • 0
    Genius 3145 points

    I suppose that the observed delay of 2 seconds corresponds in fact to the delay of the lower layer.

    When the NWKMGR calls the ZSTACK, and the ZSTACK has a timeout, then this is reflected in the response time.

    I had increased the delay for the NWKMGR to 5, but the ZSTACK was still operating on 2 seconds.

    Therefore, it looks like there is no use in having big SRSP transaction response times.
    The expiry time of the caller just has to be slightly bigger than the delay of the process that is called.

    IMHO we have the following setup for SRSP transactions, with "any" man in the middle begin capable of starting a SRSP to its children (e.g., the NWKMGR does not need the GATEWAYSVR to start a transaction), and a parent can bypass a service down in the chain (the GATEWAYSVR is also connected directly to the ZLSZNP).:

    * GATEWAYSVR > NWKMGR > ZLSZNP > NPI > SOC

    * OTASVR > NWKMGR > ZLSZNP > NPI > SOC

    So we just need to make sure that the delays of the parents are slightly higher

    Finally I noticed this issue because I haved added response verifications to the SRSP process, and some replies are still supposed to be failures resulting in timeouts.  So the above was not so apparent in the standard code, but if we want the parent to receive the timeout response from the next server, then its delay has to be slightly higher.

    I am going to make the timeouts smaller (like 500ms or less) with a slight difference between the servers (200ms or less) and see where that goes.  So I need to make the usec part configureable as well through the compilations options from the CLI.